You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sudha Ponnaganti (JIRA)" <ji...@apache.org> on 2013/12/31 15:19:51 UTC
[jira] [Commented] (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:comment-tabpanel&focusedCommentId=13859497#comment-13859497 ]
Sudha Ponnaganti commented on CLOUDSTACK-4444:
----------------------------------------------
I don't think this is still an issue. Can this be closed??
> 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.1.5#6160)