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 59D9B10583 for ; Thu, 22 Aug 2013 09:04:53 +0000 (UTC) Received: (qmail 36121 invoked by uid 500); 22 Aug 2013 09:04:53 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 36080 invoked by uid 500); 22 Aug 2013 09:04:53 -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 35897 invoked by uid 500); 22 Aug 2013 09:04:51 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 35887 invoked by uid 99); 22 Aug 2013 09:04:51 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 22 Aug 2013 09:04:51 +0000 Date: Thu, 22 Aug 2013 09:04:51 +0000 (UTC) From: "vaibhav srivastava (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Created] (CLOUDSTACK-4444) Can not create Vm using Cloud stack 4.2 and Xenserver6.0 MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 vaibhav srivastava created CLOUDSTACK-4444: ---------------------------------------------- Summary: Can not create Vm using Cloud stack 4.2 and Xenserver= 6.0 Key: CLOUDSTACK-4444 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4444 Project: CloudStack Issue Type: Test Security Level: Public (Anyone can view this level - this is the defa= ult.) Components: Management Server, XenServer Affects Versions: 4.2.0 Environment: Debian and Xenserver Reporter: vaibhav srivastava I get following errors while trying to create VM using default centos templ= ate: DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248267: Sending { Cmd , MgmtId: 7078760= 9328613, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.c= ommand.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObj= ectTO":{"path":"a83903a1-22fd-4fca-b7ed-3ab7ffa4d3ec","origUrl":"http://dow= nload.cloud.com/templates/4.2/systemvmtemplate-2013-06-12-master-xen.vhd.bz= 2","uuid":"4e10319f-0af1-11e3-ab63-4061864efbe5","id":1,"format":"VHD","acc= ountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"displa= yText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.clouds= tack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc4-4cc9-3dcb-9a25-2cefca= 41e934","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"= /export1/primary/primary123","port":2049}},"name":"routing-1","hypervisorTy= pe":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectT= O":{"uuid":"ddf51060-6a3e-4b6f-8767-5b982d11b392","volumeType":"ROOT","data= Store":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5e= ebc4-4cc9-3dcb-9a25-2cefca41e934","id":1,"poolType":"NetworkFilesystem","ho= st":"192.168.1.2","path":"/export1/primary/primary123","port":2049}},"name"= :"ROOT-4","size":2101252608,"volumeId":5,"vmName":"r-4-VM","accountId":1,"f= ormat":"VHD","id":5,"hypervisorType":"None"}},"executeInSequence":false,"wa= it":0}}] } DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248267: Executing: { Cmd , MgmtId: 7078= 7609328613, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storag= e.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.Template= ObjectTO":{"path":"a83903a1-22fd-4fca-b7ed-3ab7ffa4d3ec","origUrl":"http://= download.cloud.com/templates/4.2/systemvmtemplate-2013-06-12-master-xen.vhd= .bz2","uuid":"4e10319f-0af1-11e3-ab63-4061864efbe5","id":1,"format":"VHD","= accountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"dis= playText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.clo= udstack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc4-4cc9-3dcb-9a25-2ce= fca41e934","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path= ":"/export1/primary/primary123","port":2049}},"name":"routing-1","hyperviso= rType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObje= ctTO":{"uuid":"ddf51060-6a3e-4b6f-8767-5b982d11b392","volumeType":"ROOT","d= ataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"e= b5eebc4-4cc9-3dcb-9a25-2cefca41e934","id":1,"poolType":"NetworkFilesystem",= "host":"192.168.1.2","path":"/export1/primary/primary123","port":2049}},"na= me":"ROOT-4","size":2101252608,"volumeId":5,"vmName":"r-4-VM","accountId":1= ,"format":"VHD","id":5,"hypervisorType":"None"}},"executeInSequence":false,= "wait":0}}] } DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-120:) Seq 1-167424826= 7: Executing request DEBUG [xen.resource.XenServerStorageProcessor] (DirectAgent-120:) Succesful= ly created VDI: Uuid =3D 03f59c06-5704-4999-a4f0-50376a4618f4 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-120:) Seq 1-167424826= 7: Response Received:=20 DEBUG [agent.transport.Request] (DirectAgent-120:) Seq 1-1674248267: Proces= sing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"org.= apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cl= oudstack.storage.to.VolumeObjectTO":{"name":"ROOT-4","size":2097152000,"pat= h":"03f59c06-5704-4999-a4f0-50376a4618f4","accountId":0,"id":0}},"result":t= rue,"wait":0}}] } DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248267: Received: { Ans: , MgmtId: 7078= 7609328613, via: 1, Ver: v1, Flags: 10, { CopyCmdAnswer } } DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:j= ob-8 =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Boot Args for VM[DomainR= outer|r-4-VM]: template=3DdomP name=3Dr-4-VM eth0ip=3D192.168.1.44 eth0mas= k=3D255.255.255.0 gateway=3D192.168.1.1 domain=3Dcs1cloud.internal dhcprang= e=3D192.168.1.1 eth1ip=3D169.254.3.72 eth1mask=3D255.255.0.0 type=3Ddhcpsrv= r disable_rp_filter=3Dtrue dns1=3D203.241.132.34 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:j= ob-8 =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Resending ipAssoc, port = forwarding, load balancing rules as a part of Virtual router start DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:j= ob-8 =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Found 0 firewall Egress = rule(s) to apply as a part of domR VM[DomainRouter|r-4-VM] start. DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:j= ob-8 =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Found0ip Aliases to revo= ke on the router as a part of dhcp configuration DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:j= ob-8 =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Found0ip Aliases to appl= y on the router as a part of dhcp configuration DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:j= ob-8 =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Reapplying dhcp entries = as a part of domR VM[DomainRouter|r-4-VM] start... DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:j= ob-8 =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Reapplying vm data (user= Data and metaData) entries as a part of domR VM[DomainRouter|r-4-VM] start.= .. DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248268: Sending { Cmd , MgmtId: 7078760= 9328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StartComman= d":{"vm":{"id":4,"name":"r-4-VM","bootloader":"PyGrub","type":"DomainRouter= ","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217= 728,"arch":"i686","os":"Debian GNU/Linux 7(32-bit)","bootArgs":" template= =3DdomP name=3Dr-4-VM eth0ip=3D192.168.1.44 eth0mask=3D255.255.255.0 gatewa= y=3D192.168.1.1 domain=3Dcs1cloud.internal dhcprange=3D192.168.1.1 eth1ip= =3D169.254.3.72 eth1mask=3D255.255.0.0 type=3Ddhcpsrvr disable_rp_filter=3D= true dns1=3D203.241.132.34","rebootOnCrash":false,"enableHA":true,"limitCpu= Use":false,"enableDynamicallyScaleVm":false,"vncPassword":"a911ebdf5c7d3d03= ","params":{},"uuid":"199ee4b9-5c29-4854-b22f-d598aa39806c","disks":[{"data= ":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"ddf51060-6a3e= -4b6f-8767-5b982d11b392","volumeType":"ROOT","dataStore":{"org.apache.cloud= stack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc4-4cc9-3dcb-9a25-2cefc= a41e934","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":= "/export1/primary/primary123","port":2049}},"name":"ROOT-4","size":20971520= 00,"path":"03f59c06-5704-4999-a4f0-50376a4618f4","volumeId":5,"vmName":"r-4= -VM","accountId":1,"format":"VHD","id":5,"hypervisorType":"XenServer"}},"di= skSeq":0,"type":"ROOT"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defau= ltNic":true,"uuid":"07f89bf6-5768-458b-aca1-876f4ba2549f","ip":"192.168.1.4= 4","netmask":"255.255.255.0","gateway":"192.168.1.1","mac":"06:f3:ec:00:00:= 2b","dns1":"203.241.132.34","broadcastType":"Native","type":"Guest","broadc= astUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupE= nabled":true},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":= "372b7c20-0b08-41cf-9ab4-d68ce403fe31","ip":"169.254.3.72","netmask":"255.2= 55.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:03:48","broadcastType":"= LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"hostIp":"192= .168.1.4","executeInSequence":false,"wait":0}},{"com.cloud.agent.api.check.= CheckSshCommand":{"ip":"169.254.3.72","port":3922,"interval":6,"retries":10= 0,"name":"r-4-VM","wait":0}},{"com.cloud.agent.api.GetDomRVersionCmd":{"acc= essDetails":{"router.ip":"169.254.3.72","router.name":"r-4-VM"},"wait":0}},= {}] } DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248268: Executing: { Cmd , MgmtId: 7078= 7609328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StartCom= mand":{"vm":{"id":4,"name":"r-4-VM","bootloader":"PyGrub","type":"DomainRou= ter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134= 217728,"arch":"i686","os":"Debian GNU/Linux 7(32-bit)","bootArgs":" templat= e=3DdomP name=3Dr-4-VM eth0ip=3D192.168.1.44 eth0mask=3D255.255.255.0 gatew= ay=3D192.168.1.1 domain=3Dcs1cloud.internal dhcprange=3D192.168.1.1 eth1ip= =3D169.254.3.72 eth1mask=3D255.255.0.0 type=3Ddhcpsrvr disable_rp_filter=3D= true dns1=3D203.241.132.34","rebootOnCrash":false,"enableHA":true,"limitCpu= Use":false,"enableDynamicallyScaleVm":false,"vncPassword":"a911ebdf5c7d3d03= ","params":{},"uuid":"199ee4b9-5c29-4854-b22f-d598aa39806c","disks":[{"data= ":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"ddf51060-6a3e= -4b6f-8767-5b982d11b392","volumeType":"ROOT","dataStore":{"org.apache.cloud= stack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc4-4cc9-3dcb-9a25-2cefc= a41e934","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":= "/export1/primary/primary123","port":2049}},"name":"ROOT-4","size":20971520= 00,"path":"03f59c06-5704-4999-a4f0-50376a4618f4","volumeId":5,"vmName":"r-4= -VM","accountId":1,"format":"VHD","id":5,"hypervisorType":"XenServer"}},"di= skSeq":0,"type":"ROOT"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defau= ltNic":true,"uuid":"07f89bf6-5768-458b-aca1-876f4ba2549f","ip":"192.168.1.4= 4","netmask":"255.255.255.0","gateway":"192.168.1.1","mac":"06:f3:ec:00:00:= 2b","dns1":"203.241.132.34","broadcastType":"Native","type":"Guest","broadc= astUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupE= nabled":true},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":= "372b7c20-0b08-41cf-9ab4-d68ce403fe31","ip":"169.254.3.72","netmask":"255.2= 55.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:03:48","broadcastType":"= LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"hostIp":"192= .168.1.4","executeInSequence":false,"wait":0}},{"com.cloud.agent.api.check.= CheckSshCommand":{"ip":"169.254.3.72","port":3922,"interval":6,"retries":10= 0,"name":"r-4-VM","wait":0}},{"com.cloud.agent.api.GetDomRVersionCmd":{"acc= essDetails":{"router.ip":"169.254.3.72","router.name":"r-4-VM"},"wait":0}},= {}] } DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-127:) Seq 1-167424826= 8: Executing request DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) 1. The VM r-4-VM= is in Starting state. DEBUG [xen.resource.XenServer56FP1Resource] (DirectAgent-127:) Created VM 6= 38ae85e-66a8-f5b5-66a3-053366983ece for r-4-VM DEBUG [xen.resource.XenServer56FP1Resource] (DirectAgent-127:) PV args are = -- quiet console=3Dhvc0%template=3DdomP%name=3Dr-4-VM%eth0ip=3D192.168.1.44= %eth0mask=3D255.255.255.0%gateway=3D192.168.1.1%domain=3Dcs1cloud.internal%= dhcprange=3D192.168.1.1%eth1ip=3D169.254.3.72%eth1mask=3D255.255.0.0%type= =3Ddhcpsrvr%disable_rp_filter=3Dtrue%dns1=3D203.241.132.34 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) VBD 7587c03d-899= b-5ed3-62b9-60a6b7d411b7 created for com.cloud.agent.api.to.DiskTO@1df867e DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Creating VIF for= r-4-VM on nic [Nic:Guest-192.168.1.44-vlan://untagged] DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Created a vif fd= 3d6f87-ce4c-24c5-0dd1-da2173bbeb0e on 0 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Creating VIF for= r-4-VM on nic [Nic:Control-169.254.3.72-null] DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) already have a v= if on dom0 for link local network DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377153982452 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Created a vif c0= e4ab97-ead4-ffd1-d6e4-d6098b5a8a7e on 1 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377153982452 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:) SeqA 2-281= : Processing Seq 2-281: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{= "com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadI= nfo":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:) SeqA 2-281= : Sending Seq 2-281: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fla= gs: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait= ":0}}] } DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377153985453 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377153985453 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:) HostStatsCollector = is running... DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-103:) Seq 1-167424826= 9: Executing request DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-103:) Seq 1-167424826= 9: Response Received:=20 DEBUG [agent.transport.Request] (StatsCollector-1:) Seq 1-1674248269: Recei= ved: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { GetHos= tStatsAnswer } } DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) 2. The VM r-4-VM= is in Running state. DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Ping command por= t, 169.254.3.72:3922 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connec= t to 169.254.3.72 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377153988451 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377153988451 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377153991452 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377153991452 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:) Zone = 1 is ready to launch secondary storage VM DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:) Zone 1= is ready to launch console proxy DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-23:) Ping from 1 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:) SeqA 2-28= 2: Processing Seq 2-282: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [= {"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_load= Info":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:) SeqA 2-28= 2: Sending Seq 2-282: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fl= ags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wai= t":0}}] } DEBUG [cloud.server.StatsCollector] (StatsCollector-1:) StorageCollector is= running... DEBUG [agent.transport.Request] (StatsCollector-1:) Seq 3-963969062: Receiv= ed: { Ans: , MgmtId: 70787609328613, via: 3, Ver: v1, Flags: 10, { GetStor= ageStatsAnswer } } DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-120:) Seq 1-167424827= 0: Executing request DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-140:) Seq 1-167424819= 6: Executing request DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 routers to update status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 networks to update RvR status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 routers to update status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 networks to update RvR status.=20 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-140:) Seq 1-167424819= 6: Response Received:=20 DEBUG [agent.transport.Request] (DirectAgent-140:) Seq 1-1674248196: Proces= sing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"com.= cloud.agent.api.ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExec= uted":false,"result":true,"wait":0}}] } DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-120:) Seq 1-167424827= 0: Response Received:=20 DEBUG [agent.transport.Request] (StatsCollector-1:) Seq 1-1674248270: Recei= ved: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { GetSto= rageStatsAnswer } } DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377153994452 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377153994452 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-11:) Ping from= 2 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-12:) Ping from= 3 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377153997455 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377153997455 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:) SeqA 2-28= 4: Processing Seq 2-284: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [= {"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_load= Info":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:) SeqA 2-28= 4: Sending Seq 2-284: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fl= ags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wai= t":0}}] } DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (HostReservationReleaseC= hecker:) Checking if any host reservation can be released ...=20 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Running Capacity Ch= ecker ...=20 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) recalculating syste= m capacity DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Executing cpu/ram c= apacity update DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (HostReservationReleaseC= hecker:) Cannot release reservation, Found 4 VMs Running on host 1 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (HostReservationReleaseC= hecker:) Done running HostReservationReleaseChecker ...=20 DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:) Found 4 VMs o= n host 1 DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:) Found 0 VM, n= ot running on host 1 DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:) No need to ca= librate cpu capacity, host:1 usedCpu: 2000 reservedCpu: 0 DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:) No need to ca= librate memory capacity, host:1 usedMem: 2013265920 reservedMem: 0 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Done executing cpu/= ram capacity update DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Executing storage c= apacity update DEBUG [cloud.storage.StorageManagerImpl] (CapacityChecker:) Successfully se= t Capacity - 990585552896 for capacity type - 3 , DataCenterId - 1, HostOrP= oolId - 1, PodId 1 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Done executing stor= age capacity update DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Executing capacity = updates for public ip and Vlans DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Done capacity updat= es for public ip and Vlans DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Executing capacity = updates for private ip DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Done executing capa= city updates for private ip DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Done recalculating = system capacity DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Done running Capaci= ty Checker ...=20 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154000455 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154000455 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connec= t to 169.254.3.72 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154003454 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154003454 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154006455 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154006455 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-14:) SeqA 2-28= 5: Processing Seq 2-285: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [= {"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_load= Info":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-14:) SeqA 2-28= 5: Sending Seq 2-285: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fl= ags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wai= t":0}}] } DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154009454 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154009454 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connec= t to 169.254.3.72 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154012453 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154012453 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154015454 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154015454 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-15:) SeqA 2-28= 6: Processing Seq 2-286: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [= {"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_load= Info":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-15:) SeqA 2-28= 6: Sending Seq 2-286: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fl= ags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wai= t":0}}] } DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154018454 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154018454 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154021454 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154021454 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:) Zone = 1 is ready to launch secondary storage VM DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:) Zone 1= is ready to launch console proxy DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connec= t to 169.254.3.72 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 routers to update status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 networks to update RvR status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 routers to update status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 networks to update RvR status.=20 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154024453 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154024453 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistVirtualMachines&response=3Djson&ses= sionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=3Dtrue&page=3D1&pagesize= =3D20&_=3D1377154026328 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistVirtualMachines&response=3Djson&sessio= nkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=3Dtrue&page=3D1&pagesize=3D20= &_=3D1377154026328 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154027449 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154027449 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-1:) SeqA 2-287= : Processing Seq 2-287: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{= "com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadI= nfo":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-1:) SeqA 2-287= : Sending Seq 2-287: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fla= gs: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait= ":0}}] } DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:) Resetting hosts= suitable for reconnect DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:) Completed reset= ting hosts suitable for reconnect DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:) Acquiring hosts= for clusters already owned by this management server DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:) Completed acqui= ring hosts for clusters already owned by this management server DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:) Acquiring hosts= for clusters not owned by any management server DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:) Completed acqui= ring hosts for clusters not owned by any management server DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistVirtualMachines&response=3Djson&ses= sionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=3Dtrue&page=3D1&pagesize= =3D20&_=3D1377154028995 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistVirtualMachines&response=3Djson&sessio= nkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=3Dtrue&page=3D1&pagesize=3D20= &_=3D1377154028995 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154030454 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154030454 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connec= t to 169.254.3.72 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistZones&id=3De57d4242-fd87-4548-808a-= 3bde07bbafa8&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_= =3D1377154032992 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistZones&id=3De57d4242-fd87-4548-808a-3bd= e07bbafa8&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=3D1= 377154032992 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistNetworks&id=3Df1447461-1e02-4a41-9c= 4f-2ea2b3710db6&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D= &_=3D1377154033008 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistNetworks&id=3Df1447461-1e02-4a41-9c4f-= 2ea2b3710db6&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_= =3D1377154033008 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistVirtualMachines&id=3Da9c49db3-5768-= 41d6-9cb0-ef4fcc03b2ce&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154033041 DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistVirtualMachines&id=3Da9c49db3-5768-41d= 6-9cb0-ef4fcc03b2ce&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7= M%3D&_=3D1377154033041 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistOsTypes&response=3Djson&sessionkey= =3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=3D1377154033087 DEBUG [cloud.api.ApiServlet] (32622991@qtp-15384756-26:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistTags&response=3Djson&sessionkey=3Df= O37iDQHg1fw5zBBqJ4bz7O9n7M%3D&resourceId=3Da9c49db3-5768-41d6-9cb0-ef4fcc03= b2ce&resourceType=3DUserVm&listAll=3Dtrue&_=3D1377154033109 DEBUG [cloud.api.ApiServlet] (32622991@qtp-15384756-26:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistTags&response=3Djson&sessionkey=3DfO37= iDQHg1fw5zBBqJ4bz7O9n7M%3D&resourceId=3Da9c49db3-5768-41d6-9cb0-ef4fcc03b2c= e&resourceType=3DUserVm&listAll=3Dtrue&_=3D1377154033109 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistOsTypes&response=3Djson&sessionkey=3Df= O37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=3D1377154033087 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154033510 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154033510 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154036523 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154036523 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-2:) SeqA 2-288= : Processing Seq 2-288: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{= "com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadI= nfo":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-2:) SeqA 2-288= : Sending Seq 2-288: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fla= gs: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait= ":0}}] } DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistZones&id=3De57d4242-fd87-4548-808a-= 3bde07bbafa8&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_= =3D1377154038140 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistZones&id=3De57d4242-fd87-4548-808a-3bd= e07bbafa8&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=3D1= 377154038140 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistNetworks&id=3Df1447461-1e02-4a41-9c= 4f-2ea2b3710db6&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D= &_=3D1377154038153 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistNetworks&id=3Df1447461-1e02-4a41-9c4f-= 2ea2b3710db6&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_= =3D1377154038153 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistVirtualMachines&id=3Da9c49db3-5768-= 41d6-9cb0-ef4fcc03b2ce&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154038180 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistVirtualMachines&id=3Da9c49db3-5768-41d= 6-9cb0-ef4fcc03b2ce&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7= M%3D&_=3D1377154038180 DEBUG [cloud.api.ApiServlet] (32622991@qtp-15384756-26:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistTags&response=3Djson&sessionkey=3Df= O37iDQHg1fw5zBBqJ4bz7O9n7M%3D&resourceId=3Da9c49db3-5768-41d6-9cb0-ef4fcc03= b2ce&resourceType=3DUserVm&listAll=3Dtrue&_=3D1377154038235 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistOsTypes&response=3Djson&sessionkey= =3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=3D1377154038220 DEBUG [cloud.api.ApiServlet] (32622991@qtp-15384756-26:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistTags&response=3Djson&sessionkey=3DfO37= iDQHg1fw5zBBqJ4bz7O9n7M%3D&resourceId=3Da9c49db3-5768-41d6-9cb0-ef4fcc03b2c= e&resourceType=3DUserVm&listAll=3Dtrue&_=3D1377154038235 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistOsTypes&response=3Djson&sessionkey=3Df= O37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=3D1377154038220 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:) VmStatsCollector is= running... DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistVirtualMachines&response=3Djson&ses= sionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=3Dtrue&page=3D1&pagesize= =3D20&_=3D1377154039467 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistVirtualMachines&response=3Djson&sessio= nkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=3Dtrue&page=3D1&pagesize=3D20= &_=3D1377154039467 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154039576 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154039576 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154042574 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154042574 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connec= t to 169.254.3.72 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154045579 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154045579 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:) HostStatsCollector = is running... DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-72:) Seq 1-1674248271= : Executing request DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-72:) Seq 1-1674248271= : Response Received:=20 DEBUG [agent.transport.Request] (StatsCollector-3:) Seq 1-1674248271: Recei= ved: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { GetHos= tStatsAnswer } } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-3:) SeqA 2-289= : Processing Seq 2-289: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{= "com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadI= nfo":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-3:) SeqA 2-289= : Sending Seq 2-289: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fla= gs: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait= ":0}}] } DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154048581 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154048581 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154051579 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:) Zone = 1 is ready to launch secondary storage VM DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154051579 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:) Zone 1= is ready to launch console proxy DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-143:) Ping from 1 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-4:) SeqA 2-290= : Processing Seq 2-290: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{= "com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadI= nfo":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-4:) SeqA 2-290= : Sending Seq 2-290: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fla= gs: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait= ":0}}] } DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-72:) Seq 1-1674248196= : Executing request DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 routers to update status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 networks to update RvR status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 routers to update status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 networks to update RvR status.=20 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-72:) Seq 1-1674248196= : Response Received:=20 DEBUG [agent.transport.Request] (DirectAgent-72:) Seq 1-1674248196: Process= ing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"com.c= loud.agent.api.ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecu= ted":false,"result":true,"wait":0}}] } DEBUG [cloud.server.StatsCollector] (StatsCollector-1:) StorageCollector is= running... DEBUG [agent.transport.Request] (StatsCollector-1:) Seq 3-963969063: Receiv= ed: { Ans: , MgmtId: 70787609328613, via: 3, Ver: v1, Flags: 10, { GetStor= ageStatsAnswer } } DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-146:) Seq 1-167424827= 2: Executing request DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-146:) Seq 1-167424827= 2: Response Received:=20 DEBUG [agent.transport.Request] (StatsCollector-1:) Seq 1-1674248272: Recei= ved: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { GetSto= rageStatsAnswer } } DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154054577 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154054577 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-6:) Ping from = 2 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-7:) Ping from = 3 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154057579 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154057579 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connec= t to 169.254.3.72 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154060579 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154060579 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:) SeqA 2-292= : Processing Seq 2-292: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{= "com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadI= nfo":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:) SeqA 2-292= : Sending Seq 2-292: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fla= gs: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait= ":0}}] } DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154063579 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154063579 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154066579 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154066579 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connec= t to 169.254.3.72 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Ping command por= t succeeded for vm r-4-VM DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154069580 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154069580 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-127:) Seq 1-167424826= 8: Cancelling because one of the answers is false and it is stop on error. DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-127:) Seq 1-167424826= 8: Response Received:=20 DEBUG [agent.transport.Request] (DirectAgent-127:) Seq 1-1674248268: Proces= sing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"com.= cloud.agent.api.StartAnswer":{"vm":{"id":4,"name":"r-4-VM","bootloader":"Py= Grub","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam"= :134217728,"maxRam":134217728,"arch":"i686","os":"Debian GNU/Linux 7(32-bit= )","bootArgs":" template=3DdomP name=3Dr-4-VM eth0ip=3D192.168.1.44 eth0mas= k=3D255.255.255.0 gateway=3D192.168.1.1 domain=3Dcs1cloud.internal dhcprang= e=3D192.168.1.1 eth1ip=3D169.254.3.72 eth1mask=3D255.255.0.0 type=3Ddhcpsrv= r disable_rp_filter=3Dtrue dns1=3D203.241.132.34","rebootOnCrash":false,"en= ableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassw= ord":"a911ebdf5c7d3d03","params":{},"uuid":"199ee4b9-5c29-4854-b22f-d598aa3= 9806c","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":= {"uuid":"ddf51060-6a3e-4b6f-8767-5b982d11b392","volumeType":"ROOT","dataSto= re":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc= 4-4cc9-3dcb-9a25-2cefca41e934","id":1,"poolType":"NetworkFilesystem","host"= :"192.168.1.2","path":"/export1/primary/primary123","port":2049}},"name":"R= OOT-4","size":2097152000,"path":"03f59c06-5704-4999-a4f0-50376a4618f4","vol= umeId":5,"vmName":"r-4-VM","accountId":1,"format":"VHD","id":5,"hypervisorT= ype":"XenServer"}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":0,"netwo= rkRateMbps":200,"defaultNic":true,"uuid":"07f89bf6-5768-458b-aca1-876f4ba25= 49f","ip":"192.168.1.44","netmask":"255.255.255.0","gateway":"192.168.1.1",= "mac":"06:f3:ec:00:00:2b","dns1":"203.241.132.34","broadcastType":"Native",= "type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untag= ged","isSecurityGroupEnabled":true},{"deviceId":1,"networkRateMbps":-1,"def= aultNic":false,"uuid":"372b7c20-0b08-41cf-9ab4-d68ce403fe31","ip":"169.254.= 3.72","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:03= :48","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":= false}]},"result":true,"wait":0}},{"com.cloud.agent.api.check.CheckSshAnswe= r":{"result":true,"wait":0}},{"com.cloud.agent.api.GetDomRVersionAnswer":{"= result":false,"details":"getDomRVersionCmd failed","wait":0}}] } DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248268: Received: { Ans: , MgmtId: 7078= 7609328613, via: 1, Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer, GetD= omRVersionAnswer } } WARN [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:j= ob-8 =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Unable to get the templa= te/scripts version of router r-4-VM due to: getDomRVersionCmd failed INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) The guru did not like the answers so st= opping VM[DomainRouter|r-4-VM] DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248273: Sending { Cmd , MgmtId: 7078760= 9328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand= ":{"isProxy":false,"executeInSequence":false,"vmName":"r-4-VM","wait":0}}] = } DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248273: Executing: { Cmd , MgmtId: 7078= 7609328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopComm= and":{"isProxy":false,"executeInSequence":false,"vmName":"r-4-VM","wait":0}= }] } DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-120:) Seq 1-167424827= 3: Executing request DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-120:) 9. The VM r-4-VM= is in Stopping state DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154072579 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154072579 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:) SeqA 2-29= 3: Processing Seq 2-293: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [= {"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_load= Info":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:) SeqA 2-29= 3: Sending Seq 2-293: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fl= ags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wai= t":0}}] } DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154075580 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154075580 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-120:) 10. The VM r-4-V= M is in Stopped state DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-120:) Seq 1-167424827= 3: Response Received:=20 DEBUG [agent.transport.Request] (DirectAgent-120:) Seq 1-1674248273: Proces= sing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"com.= cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"Stop VM r= -4-VM Succeed","wait":0}}] } DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248273: Received: { Ans: , MgmtId: 7078= 7609328613, via: 1, Ver: v1, Flags: 10, { StopAnswer } } DEBUG [agent.manager.AgentManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f97= -633c-4f2b-9457-08f4f3804f8d ]) Details from executing class com.cloud.agen= t.api.StopCommand: Stop VM r-4-VM Succeed ERROR [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Failed to start instance VM[DomainRoute= r|r-4-VM] com.cloud.utils.exception.ExecutionException: Unable to start VM[DomainRout= er|r-4-VM] due to error in finalizeStart, not retrying =09at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineMan= agerImpl.java:948) =09at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImp= l.java:575) =09at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(Vir= tualNetworkApplianceManagerImpl.java:2740) =09at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirt= ualRouter(VirtualNetworkApplianceManagerImpl.java:1872) =09at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRout= ers(VirtualNetworkApplianceManagerImpl.java:1972) =09at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVir= tualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1950) =09at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterE= lement.java:221) =09at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImp= l.java:2026) =09at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.ja= va:2155) =09at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:= 2096) =09at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineMan= agerImpl.java:883) =09at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImp= l.java:575) =09at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.dep= loyVirtualMachine(VMEntityManagerImpl.java:227) =09at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImp= l.deploy(VirtualMachineEntityImpl.java:209) =09at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.= java:3406) =09at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.= java:2966) =09at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.= java:2952) =09at com.cloud.utils.component.ComponentInstantiationPostProcessor$Interce= ptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) =09at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployV= MCmd.java:420) =09at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158) =09at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:53= 1) =09at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:47= 1) =09at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) =09at java.util.concurrent.FutureTask.run(FutureTask.java:166) =09at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.= java:1146) =09at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor= .java:615) =09at java.lang.Thread.run(Thread.java:679) DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Cleaning up resources for the vm VM[Dom= ainRouter|r-4-VM] in Starting state DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248274: Sending { Cmd , MgmtId: 7078760= 9328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand= ":{"isProxy":false,"executeInSequence":false,"vmName":"r-4-VM","wait":0}}] = } DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248274: Executing: { Cmd , MgmtId: 7078= 7609328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopComm= and":{"isProxy":false,"executeInSequence":false,"vmName":"r-4-VM","wait":0}= }] } DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-141:) Seq 1-167424827= 4: Executing request INFO [xen.resource.CitrixResourceBase] (DirectAgent-141:) VM does not exis= t on XenServere34aecef-6b40-4f60-b061-4ee77ab75cd4 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-141:) Seq 1-167424827= 4: Response Received:=20 DEBUG [agent.transport.Request] (DirectAgent-141:) Seq 1-1674248274: Proces= sing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"com.= cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM does n= ot exist","wait":0}}] } DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248274: Received: { Ans: , MgmtId: 7078= 7609328613, via: 1, Ver: v1, Flags: 10, { StopAnswer } } DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:j= ob-8 =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Successfully updated use= r statistics as a part of domR VM[DomainRouter|r-4-VM] reboot/stop DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking VirtualRouter to release Nic[9-4-f= 665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking Ovs to release Nic[9-4-f665e982-c8= 50-4716-8ec7-d33725ae964e-192.168.1.44] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking SecurityGroupProvider to release N= ic[9-4-f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking VpcVirtualRouter to release Nic[9-= 4-f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking NiciraNvp to release Nic[9-4-f665e= 982-c850-4716-8ec7-d33725ae964e-192.168.1.44] DEBUG [network.element.NiciraNvpElement] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Checking if NiciraNvpElement can handle s= ervice Connectivity on network defaultGuestNetwork DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking MidoNetElement to release Nic[9-4-= f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44] DEBUG [network.element.MidoNetElement] (Job-Executor-8:job-8 =3D [ dd359f97= -633c-4f2b-9457-08f4f3804f8d ]) release called with network: Ntwk[204|Guest= |6] nic: NicProfile[9-4-f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44-v= lan://untagged vm: VM[DomainRouter|r-4-VM] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking StratosphereSsp to release Nic[9-4= -f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44] ERROR [network.element.SspElement] (Job-Executor-8:job-8 =3D [ dd359f97-633= c-4f2b-9457-08f4f3804f8d ]) ReservationContext was null for NicProfile[9-4-= f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44-vlan://untagged Ntwk[204|= Guest|6] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking InternalLbVm to release Nic[9-4-f6= 65e982-c850-4716-8ec7-d33725ae964e-192.168.1.44] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalDhcp to release Nic[9-4-f= 665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalPxe to release Nic[9-4-f6= 65e982-c850-4716-8ec7-d33725ae964e-192.168.1.44] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalUserdata to release Nic[9= -4-f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44] DEBUG [network.guru.ControlNetworkGuru] (Job-Executor-8:job-8 =3D [ dd359f9= 7-633c-4f2b-9457-08f4f3804f8d ]) Released nic: NicProfile[10-4-null-null-nu= ll DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking VirtualRouter to release Nic[10-4-= f665e982-c850-4716-8ec7-d33725ae964e-null] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking Ovs to release Nic[10-4-f665e982-c= 850-4716-8ec7-d33725ae964e-null] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking SecurityGroupProvider to release N= ic[10-4-f665e982-c850-4716-8ec7-d33725ae964e-null] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking VpcVirtualRouter to release Nic[10= -4-f665e982-c850-4716-8ec7-d33725ae964e-null] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking NiciraNvp to release Nic[10-4-f665= e982-c850-4716-8ec7-d33725ae964e-null] DEBUG [network.element.NiciraNvpElement] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Checking if NiciraNvpElement can handle s= ervice Connectivity on network null DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking MidoNetElement to release Nic[10-4= -f665e982-c850-4716-8ec7-d33725ae964e-null] DEBUG [network.element.MidoNetElement] (Job-Executor-8:job-8 =3D [ dd359f97= -633c-4f2b-9457-08f4f3804f8d ]) release called with network: Ntwk[202|Contr= ol|3] nic: NicProfile[10-4-null-null-null vm: VM[DomainRouter|r-4-VM] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking StratosphereSsp to release Nic[10-= 4-f665e982-c850-4716-8ec7-d33725ae964e-null] ERROR [network.element.SspElement] (Job-Executor-8:job-8 =3D [ dd359f97-633= c-4f2b-9457-08f4f3804f8d ]) ReservationContext was null for NicProfile[10-4= -null-null-null Ntwk[202|Control|3] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking InternalLbVm to release Nic[10-4-f= 665e982-c850-4716-8ec7-d33725ae964e-null] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalDhcp to release Nic[10-4-= f665e982-c850-4716-8ec7-d33725ae964e-null] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalPxe to release Nic[10-4-f= 665e982-c850-4716-8ec7-d33725ae964e-null] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalUserdata to release Nic[1= 0-4-f665e982-c850-4716-8ec7-d33725ae964e-null] DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Successfully released network resources= for the vm VM[DomainRouter|r-4-VM] DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Successfully cleanued up resources for = the vm VM[DomainRouter|r-4-VM] in Starting state DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistVirtualMachines&response=3Djson&ses= sionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=3Dtrue&page=3D1&pagesize= =3D20&_=3D1377154078497 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistVirtualMachines&response=3Djson&sessio= nkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=3Dtrue&page=3D1&pagesize=3D20= &_=3D1377154078497 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) VM state transitted from :Starting to S= topped with event: OperationFailedvm's original host id: null new host id: = null host id before state transition: 1 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154078602 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Hosts's actual total CPU: 63984 and CPU= after applying overprovisioning: 63984 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Hosts's actual total RAM: 12049926336 a= nd RAM after applying overprovisioning: 12049926144 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) release cpu from host: 1, old used: 200= 0,reserved: 0, actual total: 63984, total with overprovisioning: 63984; new= used: 1500,reserved:0; movedfromreserved: false,moveToReserveredfalse DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) release mem from host: 1, old used: 201= 3265920,reserved: 0, total: 12049926144; new used: 1879048192,reserved:0; m= ovedfromreserved: false,moveToReserveredfalse INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Unable to contact resource. com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreach= able: Host 1: Unable to start instance due to Unable to start VM[DomainRout= er|r-4-VM] due to error in finalizeStart, not retrying =09at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineMan= agerImpl.java:981) =09at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImp= l.java:575) =09at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(Vir= tualNetworkApplianceManagerImpl.java:2740) =09at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirt= ualRouter(VirtualNetworkApplianceManagerImpl.java:1872) =09at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRout= ers(VirtualNetworkApplianceManagerImpl.java:1972) =09at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVir= tualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1950) =09at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterE= lement.java:221) =09at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImp= l.java:2026) =09at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.ja= va:2155) =09at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:= 2096) =09at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineMan= agerImpl.java:883) =09at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImp= l.java:575) =09at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.dep= loyVirtualMachine(VMEntityManagerImpl.java:227) =09at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImp= l.deploy(VirtualMachineEntityImpl.java:209) =09at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.= java:3406) =09at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.= java:2966) =09at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.= java:2952) =09at com.cloud.utils.component.ComponentInstantiationPostProcessor$Interce= ptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) =09at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployV= MCmd.java:420) =09at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158) =09at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:53= 1) =09at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:47= 1) =09at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) =09at java.util.concurrent.FutureTask.run(FutureTask.java:166) =09at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.= java:1146) =09at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor= .java:615) =09at java.lang.Thread.run(Thread.java:679) Caused by: com.cloud.utils.exception.ExecutionException: Unable to start VM= [DomainRouter|r-4-VM] due to error in finalizeStart, not retrying =09at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineMan= agerImpl.java:948) =09... 30 more DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154078602 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Cleaning up resources for the vm VM[Use= r|vm] in Starting state DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248275: Sending { Cmd , MgmtId: 7078760= 9328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand= ":{"isProxy":false,"executeInSequence":false,"vmName":"i-2-3-VM","wait":0}}= ] } DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248275: Executing: { Cmd , MgmtId: 7078= 7609328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopComm= and":{"isProxy":false,"executeInSequence":false,"vmName":"i-2-3-VM","wait":= 0}}] } DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-18:) Seq 1-1674248275= : Executing request INFO [xen.resource.CitrixResourceBase] (DirectAgent-18:) VM does not exist= on XenServere34aecef-6b40-4f60-b061-4ee77ab75cd4 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-18:) Seq 1-1674248275= : Response Received:=20 DEBUG [agent.transport.Request] (DirectAgent-18:) Seq 1-1674248275: Process= ing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"com.c= loud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM does no= t exist","wait":0}}] } DEBUG [agent.transport.Request] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ]) Seq 1-1674248275: Received: { Ans: , MgmtId: 7078= 7609328613, via: 1, Ver: v1, Flags: 10, { StopAnswer } } DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Changing active number of nics for networ= k id=3D204 on -1 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking VirtualRouter to release Nic[8-3-1= e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking Ovs to release Nic[8-3-1e78463c-74= ff-49b0-baa6-3fbd4895edf2-192.168.1.43] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking SecurityGroupProvider to release N= ic[8-3-1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking VpcVirtualRouter to release Nic[8-= 3-1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking NiciraNvp to release Nic[8-3-1e784= 63c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43] DEBUG [network.element.NiciraNvpElement] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Checking if NiciraNvpElement can handle s= ervice Connectivity on network defaultGuestNetwork DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking MidoNetElement to release Nic[8-3-= 1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43] DEBUG [network.element.MidoNetElement] (Job-Executor-8:job-8 =3D [ dd359f97= -633c-4f2b-9457-08f4f3804f8d ]) release called with network: Ntwk[204|Guest= |6] nic: NicProfile[8-3-1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43-v= lan://untagged vm: VM[User|vm] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking StratosphereSsp to release Nic[8-3= -1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43] ERROR [network.element.SspElement] (Job-Executor-8:job-8 =3D [ dd359f97-633= c-4f2b-9457-08f4f3804f8d ]) ReservationContext was null for NicProfile[8-3-= 1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43-vlan://untagged Ntwk[204|= Guest|6] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking InternalLbVm to release Nic[8-3-1e= 78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalDhcp to release Nic[8-3-1= e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalPxe to release Nic[8-3-1e= 78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43] DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalUserdata to release Nic[8= -3-1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43] DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Successfully released network resources= for the vm VM[User|vm] DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Successfully cleanued up resources for = the vm VM[User|vm] in Starting state DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Deploy avoids pods: [], clust= ers: [], hosts: [1] DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) DeploymentPlanner allocation = algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_a3bb9853@5= 03bc4 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Trying to allocate a host and= storage pools from dc:1, pod:1,cluster:1, requested cpu: 500, requested ra= m: 536870912 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Is ROOT volume READY (pool al= ready allocated)?: No DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) DeploymentPlan has host_id sp= ecified, choosing this host and making no checks on this host: 1 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) The specified host is in avoi= d set DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Cannnot deploy to specified h= ost, returning. DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) VM state transitted from :Starting to S= topped with event: OperationFailedvm's original host id: null new host id: = null host id before state transition: 1 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Hosts's actual total CPU: 63984 and CPU= after applying overprovisioning: 63984 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Hosts's actual total RAM: 12049926336 a= nd RAM after applying overprovisioning: 12049926144 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) release cpu from host: 1, old used: 150= 0,reserved: 0, actual total: 63984, total with overprovisioning: 63984; new= used: 1000,reserved:0; movedfromreserved: false,moveToReserveredfalse DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) release mem from host: 1, old used: 187= 9048192,reserved: 0, total: 12049926144; new used: 1342177280,reserved:0; m= ovedfromreserved: false,moveToReserveredfalse DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) VM state transitted from :Stopped to St= arting with event: StartRequestedvm's original host id: null new host id: n= ull host id before state transition: null DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Successfully transitioned to start stat= e for VM[User|vm] reservation id =3D 12d94372-03e5-4683-9651-22121577e30f DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Trying to deploy VM, vm has dcId: 1 and= podId: 1 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) Deploy avoids pods: [], clusters: [], h= osts: [1] DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Deploy avoids pods: [], clust= ers: [], hosts: [1] DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) DeploymentPlanner allocation = algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_a3bb9853@5= 03bc4 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Trying to allocate a host and= storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested= ram: 536870912 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Is ROOT volume READY (pool al= ready allocated)?: No DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 =3D [ dd359f97-6= 33c-4f2b-9457-08f4f3804f8d ]) Searching resources only under specified Pod:= 1 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 =3D [ dd359f97-6= 33c-4f2b-9457-08f4f3804f8d ]) Listing clusters in order of aggregate capaci= ty, that have (atleast one host with) enough CPU and RAM capacity under thi= s Pod: 1 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 =3D [ dd359f97-6= 33c-4f2b-9457-08f4f3804f8d ]) Removing from the clusterId list these cluste= rs from avoid set: [] DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Checking resources in Cluster= : 1 under Pod: 1 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) Looking for host= s in dc: 1 pod:1 cluster:1 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) FirstFitAllocato= r has 1 hosts to check for allocation: [Host[-1-Routing]] DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) Found 1 hosts fo= r allocation after prioritization: [Host[-1-Routing]] DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) Looking for spee= d=3D500Mhz, Ram=3D512 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) Host name: local= host, hostId: 1 is in avoid set, skipping this and trying other available h= osts DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 =3D [ dd359f= 97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) Host Allocator r= eturning 0 suitable hosts DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) No suitable hosts found DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) No suitable hosts found under= this Cluster: 1 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Could not find suitable Deplo= yment Destination for this VM under any clusters, returning.=20 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 =3D [ dd359f97-6= 33c-4f2b-9457-08f4f3804f8d ]) Searching resources only under specified Pod:= 1 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 =3D [ dd359f97-6= 33c-4f2b-9457-08f4f3804f8d ]) Listing clusters in order of aggregate capaci= ty, that have (atleast one host with) enough CPU and RAM capacity under thi= s Pod: 1 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 =3D [ dd359f97-6= 33c-4f2b-9457-08f4f3804f8d ]) Removing from the clusterId list these cluste= rs from avoid set: [1] DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 =3D [ dd359f97-6= 33c-4f2b-9457-08f4f3804f8d ]) No clusters found after removing disabled clu= sters and clusters in avoid list, returning. DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) VM state transitted from :Starting to S= topped with event: OperationFailedvm's original host id: null new host id: = null host id before state transition: null DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f97-633= c-4f2b-9457-08f4f3804f8d ]) Destroying vm VM[User|vm] as it failed to creat= e on Host with Id:null DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistVirtualMachines&response=3Djson&ses= sionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=3Dtrue&page=3D1&pagesize= =3D20&_=3D1377154079362 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistVirtualMachines&response=3Djson&sessio= nkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=3Dtrue&page=3D1&pagesize=3D20= &_=3D1377154079362 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 =3D [ dd35= 9f97-633c-4f2b-9457-08f4f3804f8d ]) VM state transitted from :Stopped to Er= ror with event: OperationFailedToErrorvm's original host id: null new host = id: null host id before state transition: null WARN [apache.cloudstack.alerts] (Job-Executor-8:job-8 =3D [ dd359f97-633c-= 4f2b-9457-08f4f3804f8d ]) alertType:: 8 // dataCenterId:: 1 // podId:: 1 /= / clusterId:: null // message:: Failed to deploy Vm with Id: 3, on Host wit= h Id: null INFO [user.vm.DeployVMCmd] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4f2b-= 9457-08f4f3804f8d ]) com.cloud.exception.InsufficientServerCapacityExceptio= n: Unable to create a deployment for VM[User|vm]Scope=3Dinterface com.cloud= .dc.DataCenter; id=3D1 INFO [user.vm.DeployVMCmd] (Job-Executor-8:job-8 =3D [ dd359f97-633c-4f2b-= 9457-08f4f3804f8d ]) Unable to create a deployment for VM[User|vm] com.cloud.exception.InsufficientServerCapacityException: Unable to create a= deployment for VM[User|vm]Scope=3Dinterface com.cloud.dc.DataCenter; id=3D= 1 =09at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineMan= agerImpl.java:839) =09at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImp= l.java:575) =09at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.dep= loyVirtualMachine(VMEntityManagerImpl.java:237) =09at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImp= l.deploy(VirtualMachineEntityImpl.java:209) =09at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.= java:3406) =09at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.= java:2966) =09at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.= java:2952) =09at com.cloud.utils.component.ComponentInstantiationPostProcessor$Interce= ptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) =09at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployV= MCmd.java:420) =09at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158) =09at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:53= 1) =09at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:47= 1) =09at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) =09at java.util.concurrent.FutureTask.run(FutureTask.java:166) =09at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.= java:1146) =09at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor= .java:615) =09at java.lang.Thread.run(Thread.java:679) DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-8:job-8 =3D [ dd359f9= 7-633c-4f2b-9457-08f4f3804f8d ]) Complete async job-8 =3D [ dd359f97-633c-4= f2b-9457-08f4f3804f8d ], jobStatus: 2, resultCode: 530, result: Error Code:= 533 Error text: Unable to create a deployment for VM[User|vm] DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-63= 3c-4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4b= z7O9n7M%3D&_=3D1377154081579 DEBUG [cloud.async.AsyncJobManagerImpl] (6896058@qtp-15384756-25:) Async jo= b-8 =3D [ dd359f97-633c-4f2b-9457-08f4f3804f8d ] completed DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DqueryAsyncJobResult&jobId=3Ddd359f97-633c-= 4f2b-9457-08f4f3804f8d&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154081579 DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DSTART=3D= =3D=3D 127.0.0.1 -- GET command=3DlistVirtualMachines&id=3Da9c49db3-5768-= 41d6-9cb0-ef4fcc03b2ce&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O= 9n7M%3D&_=3D1377154081598 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:) Zone = 1 is ready to launch secondary storage VM DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) =3D=3D=3DEND=3D=3D= =3D 127.0.0.1 -- GET command=3DlistVirtualMachines&id=3Da9c49db3-5768-41d= 6-9cb0-ef4fcc03b2ce&response=3Djson&sessionkey=3DfO37iDQHg1fw5zBBqJ4bz7O9n7= M%3D&_=3D1377154081598 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:) Zone 1= is ready to launch console proxy DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:) SeqA 2-294= : Processing Seq 2-294: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{= "com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadI= nfo":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:) SeqA 2-294= : Sending Seq 2-294: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fla= gs: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait= ":0}}] } DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 routers to update status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 networks to update RvR status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 routers to update status.=20 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMoni= tor-1:) Found 0 networks to update RvR status.=20 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-11:) SeqA 2-29= 5: Processing Seq 2-295: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [= {"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_load= Info":"{\n \"connections\": []\n}","wait":0}}] } DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-11:) SeqA 2-29= 5: Sending Seq 2-295: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Fl= ags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wai= t":0}}] } -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrato= rs For more information on JIRA, see: http://www.atlassian.com/software/jira