You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Gaurav Aradhye (JIRA)" <ji...@apache.org> on 2014/09/04 10:27:52 UTC
[jira] [Closed] (CLOUDSTACK-4444) Can not create Vm using Cloud
stack 4.2 and Xenserver6.0
[ https://issues.apache.org/jira/browse/CLOUDSTACK-4444?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Gaurav Aradhye closed CLOUDSTACK-4444.
--------------------------------------
Resolution: Incomplete
>From the logs it seems like the issue is in the setup capacity and not related to product bug. Almost an year old issue and nobody is working on it, neither reporter has provided has any further comments after logging it.
Closing the issue as incomplete.
> Can not create Vm using Cloud stack 4.2 and Xenserver6.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 default.)
> 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 template:
> DEBUG [agent.transport.Request] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248267: Sending { Cmd , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"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,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc4-4cc9-3dcb-9a25-2cefca41e934","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/export1/primary/primary123","port":2049}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"ddf51060-6a3e-4b6f-8767-5b982d11b392","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc4-4cc9-3dcb-9a25-2cefca41e934","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/export1/primary/primary123","port":2049}},"name":"ROOT-4","size":2101252608,"volumeId":5,"vmName":"r-4-VM","accountId":1,"format":"VHD","id":5,"hypervisorType":"None"}},"executeInSequence":false,"wait":0}}] }
> DEBUG [agent.transport.Request] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248267: Executing: { Cmd , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"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,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc4-4cc9-3dcb-9a25-2cefca41e934","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/export1/primary/primary123","port":2049}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"ddf51060-6a3e-4b6f-8767-5b982d11b392","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc4-4cc9-3dcb-9a25-2cefca41e934","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/export1/primary/primary123","port":2049}},"name":"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-1674248267: Executing request
> DEBUG [xen.resource.XenServerStorageProcessor] (DirectAgent-120:) Succesfully created VDI: Uuid = 03f59c06-5704-4999-a4f0-50376a4618f4
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-120:) Seq 1-1674248267: Response Received:
> DEBUG [agent.transport.Request] (DirectAgent-120:) Seq 1-1674248267: Processing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"name":"ROOT-4","size":2097152000,"path":"03f59c06-5704-4999-a4f0-50376a4618f4","accountId":0,"id":0}},"result":true,"wait":0}}] }
> DEBUG [agent.transport.Request] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248267: Received: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { CopyCmdAnswer } }
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Boot Args for VM[DomainRouter|r-4-VM]: template=domP name=r-4-VM eth0ip=192.168.1.44 eth0mask=255.255.255.0 gateway=192.168.1.1 domain=cs1cloud.internal dhcprange=192.168.1.1 eth1ip=169.254.3.72 eth1mask=255.255.0.0 type=dhcpsrvr disable_rp_filter=true dns1=203.241.132.34
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:job-8 = [ 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:job-8 = [ 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:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Found0ip Aliases to revoke on the router as a part of dhcp configuration
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Found0ip Aliases to apply on the router as a part of dhcp configuration
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:job-8 = [ 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:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Reapplying vm data (userData and metaData) entries as a part of domR VM[DomainRouter|r-4-VM] start...
> DEBUG [agent.transport.Request] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248268: Sending { Cmd , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StartCommand":{"vm":{"id":4,"name":"r-4-VM","bootloader":"PyGrub","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"arch":"i686","os":"Debian GNU/Linux 7(32-bit)","bootArgs":" template=domP name=r-4-VM eth0ip=192.168.1.44 eth0mask=255.255.255.0 gateway=192.168.1.1 domain=cs1cloud.internal dhcprange=192.168.1.1 eth1ip=169.254.3.72 eth1mask=255.255.0.0 type=dhcpsrvr disable_rp_filter=true dns1=203.241.132.34","rebootOnCrash":false,"enableHA":true,"limitCpuUse":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.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc4-4cc9-3dcb-9a25-2cefca41e934","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/export1/primary/primary123","port":2049}},"name":"ROOT-4","size":2097152000,"path":"03f59c06-5704-4999-a4f0-50376a4618f4","volumeId":5,"vmName":"r-4-VM","accountId":1,"format":"VHD","id":5,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"07f89bf6-5768-458b-aca1-876f4ba2549f","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://untagged","isSecurityGroupEnabled":true},{"deviceId":1,"networkRateMbps":-1,"defaultNic":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}]},"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":100,"name":"r-4-VM","wait":0}},{"com.cloud.agent.api.GetDomRVersionCmd":{"accessDetails":{"router.ip":"169.254.3.72","router.name":"r-4-VM"},"wait":0}},{}] }
> DEBUG [agent.transport.Request] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248268: Executing: { Cmd , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StartCommand":{"vm":{"id":4,"name":"r-4-VM","bootloader":"PyGrub","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"arch":"i686","os":"Debian GNU/Linux 7(32-bit)","bootArgs":" template=domP name=r-4-VM eth0ip=192.168.1.44 eth0mask=255.255.255.0 gateway=192.168.1.1 domain=cs1cloud.internal dhcprange=192.168.1.1 eth1ip=169.254.3.72 eth1mask=255.255.0.0 type=dhcpsrvr disable_rp_filter=true dns1=203.241.132.34","rebootOnCrash":false,"enableHA":true,"limitCpuUse":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.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc4-4cc9-3dcb-9a25-2cefca41e934","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/export1/primary/primary123","port":2049}},"name":"ROOT-4","size":2097152000,"path":"03f59c06-5704-4999-a4f0-50376a4618f4","volumeId":5,"vmName":"r-4-VM","accountId":1,"format":"VHD","id":5,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"07f89bf6-5768-458b-aca1-876f4ba2549f","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://untagged","isSecurityGroupEnabled":true},{"deviceId":1,"networkRateMbps":-1,"defaultNic":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}]},"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":100,"name":"r-4-VM","wait":0}},{"com.cloud.agent.api.GetDomRVersionCmd":{"accessDetails":{"router.ip":"169.254.3.72","router.name":"r-4-VM"},"wait":0}},{}] }
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-127:) Seq 1-1674248268: 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 638ae85e-66a8-f5b5-66a3-053366983ece for r-4-VM
> DEBUG [xen.resource.XenServer56FP1Resource] (DirectAgent-127:) PV args are -- quiet console=hvc0%template=domP%name=r-4-VM%eth0ip=192.168.1.44%eth0mask=255.255.255.0%gateway=192.168.1.1%domain=cs1cloud.internal%dhcprange=192.168.1.1%eth1ip=169.254.3.72%eth1mask=255.255.0.0%type=dhcpsrvr%disable_rp_filter=true%dns1=203.241.132.34
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) VBD 7587c03d-899b-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 fd3d6f87-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 vif on dom0 for link local network
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153982452
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Created a vif c0e4ab97-ead4-ffd1-d6e4-d6098b5a8a7e on 1
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153982452
> 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,"_loadInfo":"{\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, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153985453
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153985453
> DEBUG [cloud.server.StatsCollector] (StatsCollector-1:) HostStatsCollector is running...
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-103:) Seq 1-1674248269: Executing request
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-103:) Seq 1-1674248269: Response Received:
> DEBUG [agent.transport.Request] (StatsCollector-1:) Seq 1-1674248269: Received: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) 2. The VM r-4-VM is in Running state.
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Ping command port, 169.254.3.72:3922
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connect to 169.254.3.72
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153988451
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153988451
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153991452
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153991452
> 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-282: Processing Seq 2-282: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
> DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:) SeqA 2-282: Sending Seq 2-282: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> DEBUG [cloud.server.StatsCollector] (StatsCollector-1:) StorageCollector is running...
> DEBUG [agent.transport.Request] (StatsCollector-1:) Seq 3-963969062: Received: { Ans: , MgmtId: 70787609328613, via: 3, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-120:) Seq 1-1674248270: Executing request
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-140:) Seq 1-1674248196: Executing request
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 routers to update status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 networks to update RvR status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 routers to update status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 networks to update RvR status.
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-140:) Seq 1-1674248196: Response Received:
> DEBUG [agent.transport.Request] (DirectAgent-140:) Seq 1-1674248196: Processing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] }
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-120:) Seq 1-1674248270: Response Received:
> DEBUG [agent.transport.Request] (StatsCollector-1:) Seq 1-1674248270: Received: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153994452
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153994452
> 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:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153997455
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377153997455
> DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:) SeqA 2-284: Processing Seq 2-284: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
> DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:) SeqA 2-284: Sending Seq 2-284: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (HostReservationReleaseChecker:) Checking if any host reservation can be released ...
> DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Running Capacity Checker ...
> DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) recalculating system capacity
> DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Executing cpu/ram capacity update
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (HostReservationReleaseChecker:) Cannot release reservation, Found 4 VMs Running on host 1
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (HostReservationReleaseChecker:) Done running HostReservationReleaseChecker ...
> DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:) Found 4 VMs on host 1
> DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:) Found 0 VM, not running on host 1
> DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:) No need to calibrate cpu capacity, host:1 usedCpu: 2000 reservedCpu: 0
> DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:) No need to calibrate 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 capacity update
> DEBUG [cloud.storage.StorageManagerImpl] (CapacityChecker:) Successfully set Capacity - 990585552896 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 1, PodId 1
> DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Done executing storage capacity update
> DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Executing capacity updates for public ip and Vlans
> DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Done capacity updates for public ip and Vlans
> DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Executing capacity updates for private ip
> DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Done executing capacity updates for private ip
> DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Done recalculating system capacity
> DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:) Done running Capacity Checker ...
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154000455
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154000455
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connect to 169.254.3.72
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154003454
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154003454
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154006455
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154006455
> DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-14:) SeqA 2-285: Processing Seq 2-285: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
> DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-14:) SeqA 2-285: Sending Seq 2-285: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154009454
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154009454
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connect to 169.254.3.72
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154012453
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154012453
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154015454
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154015454
> DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-15:) SeqA 2-286: Processing Seq 2-286: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
> DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-15:) SeqA 2-286: Sending Seq 2-286: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154018454
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154018454
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154021454
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154021454
> 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 connect to 169.254.3.72
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 routers to update status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 networks to update RvR status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 routers to update status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 networks to update RvR status.
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154024453
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154024453
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=listVirtualMachines&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=true&page=1&pagesize=20&_=1377154026328
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=listVirtualMachines&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=true&page=1&pagesize=20&_=1377154026328
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154027449
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154027449
> 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,"_loadInfo":"{\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, Flags: 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 resetting 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 acquiring 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 acquiring hosts for clusters not owned by any management server
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=listVirtualMachines&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=true&page=1&pagesize=20&_=1377154028995
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=listVirtualMachines&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=true&page=1&pagesize=20&_=1377154028995
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154030454
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154030454
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connect to 169.254.3.72
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=listZones&id=e57d4242-fd87-4548-808a-3bde07bbafa8&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154032992
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=listZones&id=e57d4242-fd87-4548-808a-3bde07bbafa8&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154032992
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=listNetworks&id=f1447461-1e02-4a41-9c4f-2ea2b3710db6&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154033008
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=listNetworks&id=f1447461-1e02-4a41-9c4f-2ea2b3710db6&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154033008
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===START=== 127.0.0.1 -- GET command=listVirtualMachines&id=a9c49db3-5768-41d6-9cb0-ef4fcc03b2ce&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154033041
> DEBUG [cloud.api.ApiServlet] (15517902@qtp-15384756-22:) ===END=== 127.0.0.1 -- GET command=listVirtualMachines&id=a9c49db3-5768-41d6-9cb0-ef4fcc03b2ce&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154033041
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=listOsTypes&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154033087
> DEBUG [cloud.api.ApiServlet] (32622991@qtp-15384756-26:) ===START=== 127.0.0.1 -- GET command=listTags&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&resourceId=a9c49db3-5768-41d6-9cb0-ef4fcc03b2ce&resourceType=UserVm&listAll=true&_=1377154033109
> DEBUG [cloud.api.ApiServlet] (32622991@qtp-15384756-26:) ===END=== 127.0.0.1 -- GET command=listTags&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&resourceId=a9c49db3-5768-41d6-9cb0-ef4fcc03b2ce&resourceType=UserVm&listAll=true&_=1377154033109
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=listOsTypes&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154033087
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154033510
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154033510
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154036523
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154036523
> 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,"_loadInfo":"{\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, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=listZones&id=e57d4242-fd87-4548-808a-3bde07bbafa8&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154038140
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=listZones&id=e57d4242-fd87-4548-808a-3bde07bbafa8&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154038140
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=listNetworks&id=f1447461-1e02-4a41-9c4f-2ea2b3710db6&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154038153
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=listNetworks&id=f1447461-1e02-4a41-9c4f-2ea2b3710db6&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154038153
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=listVirtualMachines&id=a9c49db3-5768-41d6-9cb0-ef4fcc03b2ce&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154038180
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=listVirtualMachines&id=a9c49db3-5768-41d6-9cb0-ef4fcc03b2ce&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154038180
> DEBUG [cloud.api.ApiServlet] (32622991@qtp-15384756-26:) ===START=== 127.0.0.1 -- GET command=listTags&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&resourceId=a9c49db3-5768-41d6-9cb0-ef4fcc03b2ce&resourceType=UserVm&listAll=true&_=1377154038235
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=listOsTypes&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154038220
> DEBUG [cloud.api.ApiServlet] (32622991@qtp-15384756-26:) ===END=== 127.0.0.1 -- GET command=listTags&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&resourceId=a9c49db3-5768-41d6-9cb0-ef4fcc03b2ce&resourceType=UserVm&listAll=true&_=1377154038235
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=listOsTypes&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154038220
> DEBUG [cloud.server.StatsCollector] (StatsCollector-1:) VmStatsCollector is running...
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=listVirtualMachines&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=true&page=1&pagesize=20&_=1377154039467
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=listVirtualMachines&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=true&page=1&pagesize=20&_=1377154039467
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154039576
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154039576
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154042574
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154042574
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connect to 169.254.3.72
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154045579
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154045579
> 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:
> DEBUG [agent.transport.Request] (StatsCollector-3:) Seq 1-1674248271: Received: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 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,"_loadInfo":"{\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, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154048581
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154048581
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154051579
> DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:) Zone 1 is ready to launch secondary storage VM
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154051579
> 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,"_loadInfo":"{\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, Flags: 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] (RouterStatusMonitor-1:) Found 0 routers to update status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 networks to update RvR status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 routers to update status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 networks to update RvR status.
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-72:) Seq 1-1674248196: Response Received:
> DEBUG [agent.transport.Request] (DirectAgent-72:) Seq 1-1674248196: Processing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] }
> DEBUG [cloud.server.StatsCollector] (StatsCollector-1:) StorageCollector is running...
> DEBUG [agent.transport.Request] (StatsCollector-1:) Seq 3-963969063: Received: { Ans: , MgmtId: 70787609328613, via: 3, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-146:) Seq 1-1674248272: Executing request
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-146:) Seq 1-1674248272: Response Received:
> DEBUG [agent.transport.Request] (StatsCollector-1:) Seq 1-1674248272: Received: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154054577
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154054577
> 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:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154057579
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154057579
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connect to 169.254.3.72
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154060579
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154060579
> 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,"_loadInfo":"{\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, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154063579
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154063579
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154066579
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154066579
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Trying to connect to 169.254.3.72
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-127:) Ping command port succeeded for vm r-4-VM
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154069580
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154069580
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-127:) Seq 1-1674248268: Cancelling because one of the answers is false and it is stop on error.
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-127:) Seq 1-1674248268: Response Received:
> DEBUG [agent.transport.Request] (DirectAgent-127:) Seq 1-1674248268: Processing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":4,"name":"r-4-VM","bootloader":"PyGrub","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"arch":"i686","os":"Debian GNU/Linux 7(32-bit)","bootArgs":" template=domP name=r-4-VM eth0ip=192.168.1.44 eth0mask=255.255.255.0 gateway=192.168.1.1 domain=cs1cloud.internal dhcprange=192.168.1.1 eth1ip=169.254.3.72 eth1mask=255.255.0.0 type=dhcpsrvr disable_rp_filter=true dns1=203.241.132.34","rebootOnCrash":false,"enableHA":true,"limitCpuUse":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.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"eb5eebc4-4cc9-3dcb-9a25-2cefca41e934","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/export1/primary/primary123","port":2049}},"name":"ROOT-4","size":2097152000,"path":"03f59c06-5704-4999-a4f0-50376a4618f4","volumeId":5,"vmName":"r-4-VM","accountId":1,"format":"VHD","id":5,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"07f89bf6-5768-458b-aca1-876f4ba2549f","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://untagged","isSecurityGroupEnabled":true},{"deviceId":1,"networkRateMbps":-1,"defaultNic":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.CheckSshAnswer":{"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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248268: Received: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer, GetDomRVersionAnswer } }
> WARN [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Unable to get the template/scripts version of router r-4-VM due to: getDomRVersionCmd failed
> INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) The guru did not like the answers so stopping VM[DomainRouter|r-4-VM]
> DEBUG [agent.transport.Request] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248273: Sending { Cmd , MgmtId: 70787609328613, 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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248273: Executing: { Cmd , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"r-4-VM","wait":0}}] }
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-120:) Seq 1-1674248273: 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:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154072579
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154072579
> DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:) SeqA 2-293: Processing Seq 2-293: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
> DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:) SeqA 2-293: Sending Seq 2-293: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154075580
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154075580
> DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-120:) 10. The VM r-4-VM is in Stopped state
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-120:) Seq 1-1674248273: Response Received:
> DEBUG [agent.transport.Request] (DirectAgent-120:) Seq 1-1674248273: Processing: { 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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248273: Received: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { StopAnswer } }
> DEBUG [agent.manager.AgentManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Details from executing class com.cloud.agent.api.StopCommand: Stop VM r-4-VM Succeed
> ERROR [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Failed to start instance VM[DomainRouter|r-4-VM]
> com.cloud.utils.exception.ExecutionException: Unable to start VM[DomainRouter|r-4-VM] due to error in finalizeStart, not retrying
> at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:948)
> at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:575)
> at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2740)
> at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1872)
> at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1972)
> at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1950)
> at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.java:221)
> at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2026)
> at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2155)
> at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2096)
> at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:883)
> at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:575)
> at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
> at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:679)
> DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Cleaning up resources for the vm VM[DomainRouter|r-4-VM] in Starting state
> DEBUG [agent.transport.Request] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248274: Sending { Cmd , MgmtId: 70787609328613, 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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248274: Executing: { Cmd , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"r-4-VM","wait":0}}] }
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-141:) Seq 1-1674248274: Executing request
> INFO [xen.resource.CitrixResourceBase] (DirectAgent-141:) VM does not exist on XenServere34aecef-6b40-4f60-b061-4ee77ab75cd4
> DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-141:) Seq 1-1674248274: Response Received:
> DEBUG [agent.transport.Request] (DirectAgent-141:) Seq 1-1674248274: Processing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM does not exist","wait":0}}] }
> DEBUG [agent.transport.Request] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248274: Received: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { StopAnswer } }
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Successfully updated user statistics as a part of domR VM[DomainRouter|r-4-VM] reboot/stop
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking VirtualRouter to release Nic[9-4-f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking Ovs to release Nic[9-4-f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking SecurityGroupProvider to release Nic[9-4-f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking NiciraNvp to release Nic[9-4-f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44]
> DEBUG [network.element.NiciraNvpElement] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Checking if NiciraNvpElement can handle service Connectivity on network defaultGuestNetwork
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ 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-vlan://untagged vm: VM[DomainRouter|r-4-VM]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking InternalLbVm to release Nic[9-4-f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalDhcp to release Nic[9-4-f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalPxe to release Nic[9-4-f665e982-c850-4716-8ec7-d33725ae964e-192.168.1.44]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Released nic: NicProfile[10-4-null-null-null
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking Ovs to release Nic[10-4-f665e982-c850-4716-8ec7-d33725ae964e-null]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking SecurityGroupProvider to release Nic[10-4-f665e982-c850-4716-8ec7-d33725ae964e-null]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking NiciraNvp to release Nic[10-4-f665e982-c850-4716-8ec7-d33725ae964e-null]
> DEBUG [network.element.NiciraNvpElement] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Checking if NiciraNvpElement can handle service Connectivity on network null
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) release called with network: Ntwk[202|Control|3] nic: NicProfile[10-4-null-null-null vm: VM[DomainRouter|r-4-VM]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking InternalLbVm to release Nic[10-4-f665e982-c850-4716-8ec7-d33725ae964e-null]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalPxe to release Nic[10-4-f665e982-c850-4716-8ec7-d33725ae964e-null]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalUserdata to release Nic[10-4-f665e982-c850-4716-8ec7-d33725ae964e-null]
> DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-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:) ===START=== 127.0.0.1 -- GET command=listVirtualMachines&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=true&page=1&pagesize=20&_=1377154078497
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=listVirtualMachines&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=true&page=1&pagesize=20&_=1377154078497
> DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 1
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154078602
> DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Hosts's actual total RAM: 12049926336 and RAM after applying overprovisioning: 12049926144
> DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) release cpu from host: 1, old used: 2000,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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) release mem from host: 1, old used: 2013265920,reserved: 0, total: 12049926144; new used: 1879048192,reserved:0; movedfromreserved: false,moveToReserveredfalse
> INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Unable to contact resource.
> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Unable to start VM[DomainRouter|r-4-VM] due to error in finalizeStart, not retrying
> at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:981)
> at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:575)
> at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2740)
> at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1872)
> at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1972)
> at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1950)
> at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.java:221)
> at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2026)
> at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2155)
> at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2096)
> at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:883)
> at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:575)
> at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
> at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at 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
> at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:948)
> ... 30 more
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154078602
> DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Cleaning up resources for the vm VM[User|vm] in Starting state
> DEBUG [agent.transport.Request] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248275: Sending { Cmd , MgmtId: 70787609328613, 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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248275: Executing: { Cmd , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"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:
> DEBUG [agent.transport.Request] (DirectAgent-18:) Seq 1-1674248275: Processing: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM does not exist","wait":0}}] }
> DEBUG [agent.transport.Request] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Seq 1-1674248275: Received: { Ans: , MgmtId: 70787609328613, via: 1, Ver: v1, Flags: 10, { StopAnswer } }
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Changing active number of nics for network id=204 on -1
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking VirtualRouter to release Nic[8-3-1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking Ovs to release Nic[8-3-1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking SecurityGroupProvider to release Nic[8-3-1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking NiciraNvp to release Nic[8-3-1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43]
> DEBUG [network.element.NiciraNvpElement] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Checking if NiciraNvpElement can handle service Connectivity on network defaultGuestNetwork
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ 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-vlan://untagged vm: VM[User|vm]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking InternalLbVm to release Nic[8-3-1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalDhcp to release Nic[8-3-1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Asking BareMetalPxe to release Nic[8-3-1e78463c-74ff-49b0-baa6-3fbd4895edf2-192.168.1.43]
> DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Successfully released network resources for the vm VM[User|vm]
> DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Deploy avoids pods: [], clusters: [], hosts: [1]
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_a3bb9853@503bc4
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 500, requested ram: 536870912
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Is ROOT volume READY (pool already allocated)?: No
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) DeploymentPlan has host_id specified, choosing this host and making no checks on this host: 1
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) The specified host is in avoid set
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Cannnot deploy to specified host, returning.
> DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 1
> DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Hosts's actual total RAM: 12049926336 and RAM after applying overprovisioning: 12049926144
> DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) release cpu from host: 1, old used: 1500,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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) release mem from host: 1, old used: 1879048192,reserved: 0, total: 12049926144; new used: 1342177280,reserved:0; movedfromreserved: false,moveToReserveredfalse
> DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) VM state transitted from :Stopped to Starting with event: StartRequestedvm's original host id: null new host id: null host id before state transition: null
> DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Successfully transitioned to start state for VM[User|vm] reservation id = 12d94372-03e5-4683-9651-22121577e30f
> DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Trying to deploy VM, vm has dcId: 1 and podId: 1
> DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Deploy avoids pods: [], clusters: [], hosts: [1]
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Deploy avoids pods: [], clusters: [], hosts: [1]
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_a3bb9853@503bc4
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ 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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Is ROOT volume READY (pool already allocated)?: No
> DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Searching resources only under specified Pod: 1
> DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
> DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Removing from the clusterId list these clusters from avoid set: []
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Checking resources in Cluster: 1 under Pod: 1
> DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
> DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
> DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]]
> DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
> DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) Host name: localhost, hostId: 1 is in avoid set, skipping this and trying other available hosts
> DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ] FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) No suitable hosts found
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) No suitable hosts found under this Cluster: 1
> DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Could not find suitable Deployment Destination for this VM under any clusters, returning.
> DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Searching resources only under specified Pod: 1
> DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
> DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Removing from the clusterId list these clusters from avoid set: [1]
> DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) No clusters found after removing disabled clusters and clusters in avoid list, returning.
> DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) VM state transitted from :Starting to Stopped 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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Destroying vm VM[User|vm] as it failed to create on Host with Id:null
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=listVirtualMachines&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=true&page=1&pagesize=20&_=1377154079362
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=listVirtualMachines&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&listAll=true&page=1&pagesize=20&_=1377154079362
> DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) VM state transitted from :Stopped to Error 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 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null // message:: Failed to deploy Vm with Id: 3, on Host with Id: null
> INFO [user.vm.DeployVMCmd] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|vm]Scope=interface com.cloud.dc.DataCenter; id=1
> INFO [user.vm.DeployVMCmd] (Job-Executor-8:job-8 = [ 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=interface com.cloud.dc.DataCenter; id=1
> at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:839)
> at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:575)
> at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
> at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:679)
> DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-8:job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ]) Complete async job-8 = [ dd359f97-633c-4f2b-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:) ===START=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154081579
> DEBUG [cloud.async.AsyncJobManagerImpl] (6896058@qtp-15384756-25:) Async job-8 = [ dd359f97-633c-4f2b-9457-08f4f3804f8d ] completed
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=queryAsyncJobResult&jobId=dd359f97-633c-4f2b-9457-08f4f3804f8d&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154081579
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===START=== 127.0.0.1 -- GET command=listVirtualMachines&id=a9c49db3-5768-41d6-9cb0-ef4fcc03b2ce&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154081598
> DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:) Zone 1 is ready to launch secondary storage VM
> DEBUG [cloud.api.ApiServlet] (6896058@qtp-15384756-25:) ===END=== 127.0.0.1 -- GET command=listVirtualMachines&id=a9c49db3-5768-41d6-9cb0-ef4fcc03b2ce&response=json&sessionkey=fO37iDQHg1fw5zBBqJ4bz7O9n7M%3D&_=1377154081598
> 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,"_loadInfo":"{\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, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 routers to update status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 networks to update RvR status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 routers to update status.
> DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Found 0 networks to update RvR status.
> DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-11:) SeqA 2-295: Processing Seq 2-295: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
> DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-11:) SeqA 2-295: Sending Seq 2-295: { Ans: , MgmtId: 70787609328613, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)