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