You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Deepak Sihag <De...@infosys.com> on 2014/03/04 08:59:10 UTC

Can we boot a vm with a ubuntu 10.04 iso

Hi Team,

I am trying to boot a VM using an ISO of Ubuntu 10.04 provided by Ubuntu community. I have register the iso but when I am trying to launch an Instance it gives error.
I have tried this with cloudstack 3.0 to 4.2 all versions. Every time the same thing. So I need our help here. First thing is it possible to have a VM with GUI. If yes then how can I use Ubuntu iso.

Regards,
Deepak Sihag



**************** CAUTION - Disclaimer *****************
This e-mail contains PRIVILEGED AND CONFIDENTIAL INFORMATION intended solely 
for the use of the addressee(s). If you are not the intended recipient, please 
notify the sender by e-mail and delete the original message. Further, you are not 
to copy, disclose, or distribute this e-mail or its contents to any other person and 
any such actions are unlawful. This e-mail may contain viruses. Infosys has taken 
every reasonable precaution to minimize this risk, but is not liable for any damage 
you may sustain as a result of any virus in this e-mail. You should carry out your 
own virus checks before opening the e-mail or attachment. Infosys reserves the 
right to monitor and review the content of all messages sent to or from this e-mail 
address. Messages sent to or from this e-mail address may be stored on the 
Infosys e-mail system.
***INFOSYS******** End of Disclaimer ********INFOSYS***

Re: Can we boot a vm with a ubuntu 10.04 iso

Posted by Shanker Balan <sh...@shapeblue.com>.
On 04-Mar-2014, at 1:29 pm, Deepak Sihag <De...@infosys.com> wrote:

> Hi Team,
>
> I am trying to boot a VM using an ISO of Ubuntu 10.04 provided by Ubuntu community. I have register the iso but when I am trying to launch an Instance it gives error.
> I have tried this with cloudstack 3.0 to 4.2 all versions. Every time the same thing. So I need our help here. First thing is it possible to have a VM with GUI. If yes then how can I use Ubuntu iso.

Hi Deepak,

I am assuming you are using Xen as hypervisor. If so, then:

Ubuntu 10.04 ISO does not have Xen PV kernel and will fail to boot on
XenServer hypervisors. You have two options:

1) Set the OS type to “other” to boot from the ISO
2) Prepare a Ubuntu 10.04 template on a standalone XenServer host using the network install method.

See http://shankerbalan.net/blog/cloudstack-ubuntu-10-04-xenserver-template/ also.

Hth.


--
@shankerbalan

M: +91 98860 60539 | O: +91 (80) 67935867
shanker.balan@shapeblue.com | www.shapeblue.com | Twitter:@shapeblue
ShapeBlue Services India LLP, 22nd floor, Unit 2201A, World Trade Centre, Bangalore - 560 055

Need Enterprise Grade Support for Apache CloudStack?
Our CloudStack Infrastructure Support<http://shapeblue.com/cloudstack-infrastructure-support/> offers the best 24/7 SLA for CloudStack Environments.

Apache CloudStack Bootcamp training courses

**NEW!** CloudStack 4.2.1 training<http://shapeblue.com/cloudstack-training/>
18th-19th February 2014, Brazil. Classroom<http://shapeblue.com/cloudstack-training/>
17th-23rd March 2014, Region A. Instructor led, On-line<http://shapeblue.com/cloudstack-training/>
24th-28th March 2014, Region B. Instructor led, On-line<http://shapeblue.com/cloudstack-training/>
16th-20th June 2014, Region A. Instructor led, On-line<http://shapeblue.com/cloudstack-training/>
23rd-27th June 2014, Region B. Instructor led, On-line<http://shapeblue.com/cloudstack-training/>

This email and any attachments to it may be confidential and are intended solely for the use of the individual to whom it is addressed. Any views or opinions expressed are solely those of the author and do not necessarily represent those of Shape Blue Ltd or related companies. If you are not the intended recipient of this email, you must neither take any action based upon its contents, nor copy or show it to anyone. Please contact the sender if you believe you have received this email in error. Shape Blue Ltd is a company incorporated in England & Wales. ShapeBlue Services India LLP is a company incorporated in India and is operated under license from Shape Blue Ltd. Shape Blue Brasil Consultoria Ltda is a company incorporated in Brasil and is operated under license from Shape Blue Ltd. ShapeBlue is a registered trademark.

RE: Can we boot a vm with a ubuntu 10.04 iso

Posted by Deepak Sihag <De...@infosys.com>.
Thanks nitin and marty for your comments, here is the logs, if you can help me on this


2014-03-05 12:24:39,718 DEBUG [cloud.api.ApiDispatcher] (catalina-exec-10:null) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
2014-03-05 12:24:39,727 DEBUG [cloud.api.ApiDispatcher] (catalina-exec-10:null) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
2014-03-05 12:24:39,731 DEBUG [cloud.api.ApiDispatcher] (catalina-exec-10:null) InfrastructureEntity name is:com.cloud.offering.DiskOffering
2014-03-05 12:24:39,845 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-10:null) Allocating in the DB for vm
2014-03-05 12:24:39,856 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-10:null) Allocating entries for VM: VM[User|UbuntuISO]
2014-03-05 12:24:39,858 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-10:null) Allocating nics for VM[User|UbuntuISO]
2014-03-05 12:24:39,859 DEBUG [cloud.network.NetworkManagerImpl] (catalina-exec-10:null) Allocating nic for vm VM[User|UbuntuISO] in network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
2014-03-05 12:24:39,868 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-10:null) Allocating disks for VM[User|UbuntuISO]
2014-03-05 12:24:39,878 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-10:null) Allocation completed for VM: VM[User|UbuntuISO]
2014-03-05 12:24:39,879 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-10:null) Successfully allocated DB entry for VM[User|UbuntuISO]
2014-03-05 12:24:40,339 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-10:null) submit async job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ], details: AsyncJobVO {id:25, userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine, instanceId: 7, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdOriginator: null, cmdInfo: {"sessionkey":"DbBSRYf0DUMIlbu+YmmG/oUXm78\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","serviceOfferingId":"e6f7ae98-f9ea-4197-8b44-4f3347363f99","httpmethod":"GET","zoneId":"3fed2fb8-e33c-4fbd-bd14-3941e388205f","templateId":"90395af7-e10d-446f-a58d-0c53fd548582","response":"json","id":"7","hypervisor":"XenServer","name":"UbuntuISO","diskOfferingId":"342792cc-f249-4142-85a7-176e53a4f1c0","_":"1394002479703","ctxAccountId":"2","ctxStartEventId":"229","displayname":"UbuntuISO"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 75006878169638, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-03-05 12:24:40,342 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===END===  192.168.137.2 -- GET  command=deployVirtualMachine&zoneId=3fed2fb8-e33c-4fbd-bd14-3941e388205f&templateId=90395af7-e10d-446f-a58d-0c53fd548582&hypervisor=XenServer&serviceOfferingId=e6f7ae98-f9ea-4197-8b44-4f3347363f99&diskOfferingId=342792cc-f249-4142-85a7-176e53a4f1c0&displayname=UbuntuISO&name=UbuntuISO&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002479703
2014-03-05 12:24:40,346 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Executing org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]
2014-03-05 12:24:40,352 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
2014-03-05 12:24:40,355 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
2014-03-05 12:24:40,358 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) InfrastructureEntity name is:com.cloud.offering.DiskOffering
2014-03-05 12:24:40,527 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Deploy avoids pods: [], clusters: [], hosts: []
2014-03-05 12:24:40,529 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_691b6f1d@149675a1
2014-03-05 12:24:40,529 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 500, requested ram: 536870912
2014-03-05 12:24:40,529 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Is ROOT volume READY (pool already allocated)?: No
2014-03-05 12:24:40,529 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Searching all possible resources under this Zone: 1
2014-03-05 12:24:40,530 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2014-03-05 12:24:40,532 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Removing from the clusterId list these clusters from avoid set: []
2014-03-05 12:24:40,540 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking resources in Cluster: 1 under Pod: 1
2014-03-05 12:24:40,542 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  cluster:1
2014-03-05 12:24:40,546 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) FirstFitAllocator has 2 hosts to check for allocation: [Host[-4-Routing], Host[-1-Routing]]
2014-03-05 12:24:40,551 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Found 2 hosts for allocation after prioritization: [Host[-4-Routing], Host[-1-Routing]]
2014-03-05 12:24:40,551 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2014-03-05 12:24:40,556 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Checking if host: 4 has enough capacity for requested CPU: 500 and requested RAM: 536870912 , cpuOverprovisioningFactor: 1.0
2014-03-05 12:24:40,558 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Hosts's actual total CPU: 6384 and CPU after applying overprovisioning: 6384
2014-03-05 12:24:40,558 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Free CPU: 4884 , Requested CPU: 500
2014-03-05 12:24:40,558 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Free RAM: 1216847872 , Requested RAM: 536870912
2014-03-05 12:24:40,558 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-03-05 12:24:40,558 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 4, used: 1500, reserved: 0, actual total: 6384, total with overprovisioning: 6384; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-05 12:24:40,558 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 4, used: 1476395008, reserved: 0, total: 2693242880; requested mem: 536870912,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-05 12:24:40,558 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Found a suitable host, adding to list: 4
2014-03-05 12:24:40,562 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 500 and requested RAM: 536870912 , cpuOverprovisioningFactor: 1.0
2014-03-05 12:24:40,564 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Hosts's actual total CPU: 6384 and CPU after applying overprovisioning: 6384
2014-03-05 12:24:40,564 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Free CPU: 5884 , Requested CPU: 500
2014-03-05 12:24:40,564 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Free RAM: 2156371968 , Requested RAM: 536870912
2014-03-05 12:24:40,564 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-03-05 12:24:40,564 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 500, reserved: 0, actual total: 6384, total with overprovisioning: 6384; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-05 12:24:40,564 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 536870912, reserved: 0, total: 2693242880; requested mem: 536870912,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-05 12:24:40,564 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2014-03-05 12:24:40,564 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Host Allocator returning 2 suitable hosts
2014-03-05 12:24:40,566 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking suitable pools for volume (Id, Type): (7,ROOT)
2014-03-05 12:24:40,566 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) We need to allocate new storagepool for this volume
2014-03-05 12:24:40,567 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Calling StoragePoolAllocators to find suitable pools
2014-03-05 12:24:40,567 DEBUG [storage.allocator.LocalStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2014-03-05 12:24:40,567 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) ClusterScopeStoragePoolAllocator looking for storage pool
2014-03-05 12:24:40,567 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Looking for pools in dc: 1  pod:1  cluster:1
2014-03-05 12:24:40,572 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking if storage pool is suitable, name: null ,poolId: 1
2014-03-05 12:24:40,576 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking pool 1 for storage, totalSize: 52845084672, usedBytes: 16173760512, usedPct: 0.30605988451693555, disable threshold: 0.85
2014-03-05 12:24:40,583 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking pool: 1 for volume allocation [Vol[7|vm=7|ROOT]], maxSize : 105690169344, totalAllocatedSize : 6442450944, askingSize : 5368709120, allocated disable threshold: 0.85
2014-03-05 12:24:40,585 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking if storage pool is suitable, name: null ,poolId: 2
2014-03-05 12:24:40,589 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking pool 2 for storage, totalSize: 52845084672, usedBytes: 18500026368, usedPct: 0.35008036192630515, disable threshold: 0.85
2014-03-05 12:24:40,597 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking pool: 2 for volume allocation [Vol[7|vm=7|ROOT]], maxSize : 105690169344, totalAllocatedSize : 42949672960, askingSize : 5368709120, allocated disable threshold: 0.85
2014-03-05 12:24:40,597 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) FirstFitStoragePoolAllocator returning 2 suitable storage pools
2014-03-05 12:24:40,597 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2014-03-05 12:24:40,597 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking if host: 4 can access any suitable storage pool for volume: ROOT
2014-03-05 12:24:40,598 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Host: 4 can access pool: 1
2014-03-05 12:24:40,599 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Found a potential host id: 4 name: xenserver-gjhxstnz and associated storage pools for this VM
2014-03-05 12:24:40,600 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(4)-Storage(Volume(7|ROOT-->Pool(1))]
2014-03-05 12:24:40,705 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) 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
2014-03-05 12:24:40,705 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Successfully transitioned to start state for VM[User|UbuntuISO] reservation id = e24f0063-528a-4f4b-9119-0a27bce2911c
2014-03-05 12:24:40,858 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Trying to deploy VM, vm has dcId: 1 and podId: null
2014-03-05 12:24:40,858 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) advanceStart: DeploymentPlan is provided, using dcId:1, podId: 1, clusterId: 1, hostId: 4, poolId: null
2014-03-05 12:24:40,858 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Deploy avoids pods: null, clusters: null, hosts: null
2014-03-05 12:24:40,864 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Deploy avoids pods: [], clusters: [], hosts: []
2014-03-05 12:24:40,864 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_691b6f1d@149675a1
2014-03-05 12:24:40,865 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 500, requested ram: 536870912
2014-03-05 12:24:40,865 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Is ROOT volume READY (pool already allocated)?: No
2014-03-05 12:24:40,865 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) DeploymentPlan has host_id specified, choosing this host and making no checks on this host: 4
2014-03-05 12:24:40,866 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Looking for suitable pools for this host under zone: 1, pod: 1, cluster: 1
2014-03-05 12:24:40,867 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking suitable pools for volume (Id, Type): (7,ROOT)
2014-03-05 12:24:40,867 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) We need to allocate new storagepool for this volume
2014-03-05 12:24:40,867 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Calling StoragePoolAllocators to find suitable pools
2014-03-05 12:24:40,867 DEBUG [storage.allocator.LocalStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2014-03-05 12:24:40,867 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) ClusterScopeStoragePoolAllocator looking for storage pool
2014-03-05 12:24:40,867 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Looking for pools in dc: 1  pod:1  cluster:1
2014-03-05 12:24:40,870 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking if storage pool is suitable, name: null ,poolId: 1
2014-03-05 12:24:40,873 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking pool 1 for storage, totalSize: 52845084672, usedBytes: 16173760512, usedPct: 0.30605988451693555, disable threshold: 0.85
2014-03-05 12:24:40,880 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking pool: 1 for volume allocation [Vol[7|vm=7|ROOT]], maxSize : 105690169344, totalAllocatedSize : 6442450944, askingSize : 5368709120, allocated disable threshold: 0.85
2014-03-05 12:24:40,881 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking if storage pool is suitable, name: null ,poolId: 2
2014-03-05 12:24:40,884 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking pool 2 for storage, totalSize: 52845084672, usedBytes: 18500026368, usedPct: 0.35008036192630515, disable threshold: 0.85
2014-03-05 12:24:40,890 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking pool: 2 for volume allocation [Vol[7|vm=7|ROOT]], maxSize : 105690169344, totalAllocatedSize : 42949672960, askingSize : 5368709120, allocated disable threshold: 0.85
2014-03-05 12:24:40,890 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) FirstFitStoragePoolAllocator returning 2 suitable storage pools
2014-03-05 12:24:40,890 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2014-03-05 12:24:40,890 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking if host: 4 can access any suitable storage pool for volume: ROOT
2014-03-05 12:24:40,891 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Host: 4 can access pool: 2
2014-03-05 12:24:40,892 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Found a potential host id: 4 name: xenserver-gjhxstnz and associated storage pools for this VM
2014-03-05 12:24:40,893 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(4)-Storage(Volume(7|ROOT-->Pool(2))]
2014-03-05 12:24:40,893 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Deployment found  - P0=VM[User|UbuntuISO], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(4)-Storage(Volume(7|ROOT-->Pool(2))]
2014-03-05 12:24:41,016 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 4 host id before state transition: null
2014-03-05 12:24:41,023 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Hosts's actual total CPU: 6384 and CPU after applying overprovisioning: 6384
2014-03-05 12:24:41,023 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) We are allocating VM, increasing the used capacity of this host:4
2014-03-05 12:24:41,023 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Current Used CPU: 1500 , Free CPU:4884 ,Requested CPU: 500
2014-03-05 12:24:41,023 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Current Used RAM: 1476395008 , Free RAM:1216847872 ,Requested RAM: 536870912
2014-03-05 12:24:41,023 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) CPU STATS after allocation: for host: 4, old used: 1500, old reserved: 0, actual total: 6384, total with overprovisioning: 6384; new used:2000, reserved:0; requested cpu:500,alloc_from_last:false
2014-03-05 12:24:41,023 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) RAM STATS after allocation: for host: 4, old used: 1476395008, old reserved: 0, total: 2693242880; new used: 2013265920, reserved: 0; requested mem: 536870912,alloc_from_last:false
2014-03-05 12:24:41,091 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) VM is being created in podId: 1
2014-03-05 12:24:41,097 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Network id=204 is already implemented
2014-03-05 12:24:41,251 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Changing active number of nics for network id=204 on 1
2014-03-05 12:24:41,319 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Asking VirtualRouter to prepare for Nic[14-7-e24f0063-528a-4f4b-9119-0a27bce2911c-192.168.137.117]
2014-03-05 12:24:41,325 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Lock is acquired for network id 204 as a part of router startup in Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(4)-Storage(Volume(7|ROOT-->Pool(2))]
2014-03-05 12:24:41,327 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Lock is released for network id 204 as a part of router startup in Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(4)-Storage(Volume(7|ROOT-->Pool(2))]
2014-03-05 12:24:41,343 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Applying dhcp entry in network Ntwk[204|Guest|6]
2014-03-05 12:24:41,363 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257499: Sending  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"06:85:98:00:00:6b","vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","defaultRouter":"192.168.137.1","defaultDns":"192.168.137.114","duid":"00:03:00:01:06:85:98:00:00:6b","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.name":"r-4-VM","router.ip":"169.254.0.208"},"wait":0}}] }
2014-03-05 12:24:41,363 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257499: Executing:  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"06:85:98:00:00:6b","vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","defaultRouter":"192.168.137.1","defaultDns":"192.168.137.114","duid":"00:03:00:01:06:85:98:00:00:6b","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.name":"r-4-VM","router.ip":"169.254.0.208"},"wait":0}}] }
2014-03-05 12:24:41,363 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-243:null) Seq 4-1156257499: Executing request
2014-03-05 12:24:43,038 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Resetting hosts suitable for reconnect
2014-03-05 12:24:43,040 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed resetting hosts suitable for reconnect
2014-03-05 12:24:43,040 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters already owned by this management server
2014-03-05 12:24:43,044 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters already owned by this management server
2014-03-05 12:24:43,044 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters not owned by any management server
2014-03-05 12:24:43,044 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters not owned by any management server
2014-03-05 12:24:43,133 DEBUG [agent.manager.ClusteredAgentManagerImpl] (ClusteredAgentManager Timer:null) Found 1 unmanaged direct hosts, processing connect for them...
2014-03-05 12:24:43,133 DEBUG [agent.manager.ClusteredAgentManagerImpl] (ClusteredAgentManager Timer:null) Loading directly connected host 5(xenserver-tadnfper)
2014-03-05 12:24:43,382 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null) ===START===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002483380
2014-03-05 12:24:43,486 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null) ===END===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002483380
2014-03-05 12:24:43,847 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-243:null) Seq 4-1156257499: Response Received: 
2014-03-05 12:24:43,847 DEBUG [agent.transport.Request] (DirectAgent-243:null) Seq 4-1156257499: Processing:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
2014-03-05 12:24:43,847 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257499: Received:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, { Answer } }
2014-03-05 12:24:43,847 DEBUG [agent.manager.AgentAttache] (DirectAgent-243:null) Seq 4-1156257499: No more commands found
2014-03-05 12:24:43,860 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Applying userdata and password entry in network Ntwk[204|Guest|6]
2014-03-05 12:24:43,872 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257500: Sending  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.ip":"169.254.0.208","router.name":"r-4-VM"},"wait":0}},{"com.cloud.agent.api.routing.VmDataCommand":{"vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.ip":"169.254.0.208","router.name":"r-4-VM"},"wait":0}}] }
2014-03-05 12:24:43,872 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257500: Executing:  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.ip":"169.254.0.208","router.name":"r-4-VM"},"wait":0}},{"com.cloud.agent.api.routing.VmDataCommand":{"vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.ip":"169.254.0.208","router.name":"r-4-VM"},"wait":0}}] }
2014-03-05 12:24:43,872 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-387:null) Seq 4-1156257500: Executing request
2014-03-05 12:24:44,476 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 3-21486: Processing Seq 3-21486:  { Cmd , MgmtId: -1, via: 3, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n  \"connections\": []\n}","wait":0}}] }
2014-03-05 12:24:44,548 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 3-21486: Sending Seq 3-21486:  { Ans: , MgmtId: 75006878169638, via: 3, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-03-05 12:24:44,712 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-387:null) Seq 4-1156257500: Response Received: 
2014-03-05 12:24:44,712 DEBUG [agent.transport.Request] (DirectAgent-387:null) Seq 4-1156257500: Processing:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}},{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
2014-03-05 12:24:44,712 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257500: Received:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, { Answer, Answer } }
2014-03-05 12:24:44,712 DEBUG [agent.manager.AgentAttache] (DirectAgent-387:null) Seq 4-1156257500: No more commands found
2014-03-05 12:24:44,716 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Asking SecurityGroupProvider to prepare for Nic[14-7-e24f0063-528a-4f4b-9119-0a27bce2911c-192.168.137.117]
2014-03-05 12:24:44,726 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking if we need to prepare 1 volumes for VM[User|UbuntuISO]
2014-03-05 12:24:44,879 DEBUG [datastore.driver.CloudStackPrimaryDataStoreDriverImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Creating volume: org.apache.cloudstack.storage.volume.VolumeObject@3edd881a
2014-03-05 12:24:44,884 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 1-1024332353: Sending  { Cmd , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9482e25b-bd1e-4369-9249-dd993dcd2bcd","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a298b6e6-474e-3351-b0c7-a90ef28e1989","id":2,"poolType":"NetworkFilesystem","host":"192.168.137.8","path":"/primary","port":2049}},"name":"ROOT-7","size":5368709120,"volumeId":7,"vmName":"i-2-7-VM","accountId":2,"format":"VHD","id":7,"hypervisorType":"XenServer"}},"wait":0}}] }
2014-03-05 12:24:44,884 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 1-1024332353: Executing:  { Cmd , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9482e25b-bd1e-4369-9249-dd993dcd2bcd","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a298b6e6-474e-3351-b0c7-a90ef28e1989","id":2,"poolType":"NetworkFilesystem","host":"192.168.137.8","path":"/primary","port":2049}},"name":"ROOT-7","size":5368709120,"volumeId":7,"vmName":"i-2-7-VM","accountId":2,"format":"VHD","id":7,"hypervisorType":"XenServer"}},"wait":0}}] }
2014-03-05 12:24:44,884 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-34:null) Seq 1-1024332353: Executing request
2014-03-05 12:24:45,061 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-34:null) SR retrieved for a298b6e6-474e-3351-b0c7-a90ef28e1989
2014-03-05 12:24:45,071 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-34:null) Checking a298b6e6-474e-3351-b0c7-a90ef28e1989 or SR 8b5d731c-7d40-df1f-a4a2-35fddbc73bc7 on XS[c2d3ab1e-4e6a-42cb-85a9-5513be91d1a9-192.168.137.5]
2014-03-05 12:24:45,305 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-34:null) Seq 1-1024332353: Response Received: 
2014-03-05 12:24:45,306 DEBUG [agent.transport.Request] (DirectAgent-34:null) Seq 1-1024332353: Processing:  { Ans: , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"name":"ROOT-7","size":5368709120,"path":"7e466b68-b91b-4156-bb3c-cc3d19362fa5","accountId":0,"id":0}},"result":true,"wait":0}}] }
2014-03-05 12:24:45,306 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 1-1024332353: Received:  { Ans: , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 10, { CreateObjectAnswer } }
2014-03-05 12:24:45,485 DEBUG [storage.image.TemplateDataFactoryImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) template 206 is already in store:1, type:Image
2014-03-05 12:24:45,659 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257501: Sending  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StartCommand":{"vm":{"id":7,"name":"i-2-7-VM","bootloader":"CD","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"Ubuntu 10.04 (32-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"3dacbe8149a1aa8f","params":{},"uuid":"0bcc3371-c51f-4988-97c3-65bc3ed1fe69","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9482e25b-bd1e-4369-9249-dd993dcd2bcd","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a298b6e6-474e-3351-b0c7-a90ef28e1989","id":2,"poolType":"NetworkFilesystem","host":"192.168.137.8","path":"/primary","port":2049}},"name":"ROOT-7","size":5368709120,"path":"7e466b68-b91b-4156-bb3c-cc3d19362fa5","volumeId":7,"vmName":"i-2-7-VM","accountId":2,"format":"VHD","id":7,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/206/206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293.iso","origUrl":"http://192.168.137.8:443/ubuntu.iso","uuid":"90395af7-e10d-446f-a58d-0c53fd548582","id":206,"format":"ISO","accountId":2,"checksum":"557231ce93ae8e98e214424cb02f8761","hvm":true,"displayText":"Ubuntu 10.04 32 bit","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.137.2/export/secondary","_role":"Image"}},"name":"206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293","guestOsType":"Ubuntu 10.04 (32-bit)","hypervisorType":"None"}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"71fa94ea-17a6-4099-b5cd-fb1b9d9866f1","ip":"192.168.137.117","netmask":"255.255.255.0","gateway":"192.168.137.1","mac":"06:85:98:00:00:6b","dns1":"192.168.137.1","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"hostIp":"192.168.137.7","executeInSequence":true,"wait":0}}] }
2014-03-05 12:24:45,660 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257501: Executing:  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StartCommand":{"vm":{"id":7,"name":"i-2-7-VM","bootloader":"CD","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"Ubuntu 10.04 (32-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"3dacbe8149a1aa8f","params":{},"uuid":"0bcc3371-c51f-4988-97c3-65bc3ed1fe69","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9482e25b-bd1e-4369-9249-dd993dcd2bcd","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a298b6e6-474e-3351-b0c7-a90ef28e1989","id":2,"poolType":"NetworkFilesystem","host":"192.168.137.8","path":"/primary","port":2049}},"name":"ROOT-7","size":5368709120,"path":"7e466b68-b91b-4156-bb3c-cc3d19362fa5","volumeId":7,"vmName":"i-2-7-VM","accountId":2,"format":"VHD","id":7,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/206/206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293.iso","origUrl":"http://192.168.137.8:443/ubuntu.iso","uuid":"90395af7-e10d-446f-a58d-0c53fd548582","id":206,"format":"ISO","accountId":2,"checksum":"557231ce93ae8e98e214424cb02f8761","hvm":true,"displayText":"Ubuntu 10.04 32 bit","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.137.2/export/secondary","_role":"Image"}},"name":"206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293","guestOsType":"Ubuntu 10.04 (32-bit)","hypervisorType":"None"}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"71fa94ea-17a6-4099-b5cd-fb1b9d9866f1","ip":"192.168.137.117","netmask":"255.255.255.0","gateway":"192.168.137.1","mac":"06:85:98:00:00:6b","dns1":"192.168.137.1","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"hostIp":"192.168.137.7","executeInSequence":true,"wait":0}}] }
2014-03-05 12:24:45,661 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-424:null) Seq 4-1156257501: Executing request
2014-03-05 12:24:45,740 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-424:null) 1. The VM i-2-7-VM is in Starting state.
2014-03-05 12:24:45,793 DEBUG [xen.resource.XenServer56FP1Resource] (DirectAgent-424:null) Created VM 35d2d51c-8b28-f1ff-1848-935ca5006463 for i-2-7-VM
2014-03-05 12:24:45,855 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-424:null) VBD 2b47b407-42bb-d091-fe31-3e0149948a8f created for com.cloud.agent.api.to.DiskTO@4c757a55
2014-03-05 12:24:46,383 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===START===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002486379
2014-03-05 12:24:46,485 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===END===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002486379
2014-03-05 12:24:46,644 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-424:null) VBD 249990aa-95a6-8738-dde4-bd24f27841af created for com.cloud.agent.api.to.DiskTO@3799a6fd
2014-03-05 12:24:46,644 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-424:null) Creating VIF for i-2-7-VM on nic [Nic:Guest-192.168.137.117-vlan://untagged]
2014-03-05 12:24:46,682 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-424:null) Created a vif d450e694-686a-bce0-02e5-b9301ce2069e on 0
2014-03-05 12:24:47,803 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-34:null) Ping from 4
2014-03-05 12:24:48,145 DEBUG [xen.resource.XenServerConnectionPool] (ClusteredAgentManager Timer:null) Failed to slave local login to 192.168.137.6
2014-03-05 12:24:48,146 WARN  [cloud.resource.DiscovererBase] (ClusteredAgentManager Timer:null) Unable to configure resource due to Can not create slave connection to 192.168.137.6
2014-03-05 12:24:48,146 WARN  [agent.manager.AgentManagerImpl] (ClusteredAgentManager Timer:null) Unable to load the resource: 5
2014-03-05 12:24:48,146 DEBUG [cloud.host.Status] (ClusteredAgentManager Timer:null) Transition:[Resource state = Enabled, Agent event = AgentDisconnected, Host id = 5, name = xenserver-tadnfper]
2014-03-05 12:24:48,231 DEBUG [cloud.host.Status] (ClusteredAgentManager Timer:null) Agent status update: [id = 5; name = xenserver-tadnfper; old status = Down; event = AgentDisconnected; new status = Down; old update count = 1509; new update count = 1510]
2014-03-05 12:24:48,725 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-424:null) Task failed! Task record:                 uuid: 6c9a98da-62df-ef4b-b5f9-2b3a9a007adb
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:12 IST 2014
            finished: Wed Mar 05 12:25:14 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-X0iKpB/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

2014-03-05 12:24:48,734 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-424:null) Unable to start VM(i-2-7-VM) on host(37ec4c80-1b2f-46ab-ad12-9aa1ae625241) due to Task failed! Task record:                 uuid: 6c9a98da-62df-ef4b-b5f9-2b3a9a007adb
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:12 IST 2014
            finished: Wed Mar 05 12:25:14 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-X0iKpB/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

Task failed! Task record:                 uuid: 6c9a98da-62df-ef4b-b5f9-2b3a9a007adb
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:12 IST 2014
            finished: Wed Mar 05 12:25:14 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-X0iKpB/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3605)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3717)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1640)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:24:48,745 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-424:null) Catch Exception: class com.cloud.utils.exception.CloudRuntimeException due to com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(i-2-7-VM) on host(37ec4c80-1b2f-46ab-ad12-9aa1ae625241) due to Task failed! Task record:                 uuid: 6c9a98da-62df-ef4b-b5f9-2b3a9a007adb
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:12 IST 2014
            finished: Wed Mar 05 12:25:14 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-X0iKpB/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(i-2-7-VM) on host(37ec4c80-1b2f-46ab-ad12-9aa1ae625241) due to Task failed! Task record:                 uuid: 6c9a98da-62df-ef4b-b5f9-2b3a9a007adb
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:12 IST 2014
            finished: Wed Mar 05 12:25:14 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-X0iKpB/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3728)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1640)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:24:48,745 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-424:null) Unable to start i-2-7-VM due to 
com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(i-2-7-VM) on host(37ec4c80-1b2f-46ab-ad12-9aa1ae625241) due to Task failed! Task record:                 uuid: 6c9a98da-62df-ef4b-b5f9-2b3a9a007adb
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:12 IST 2014
            finished: Wed Mar 05 12:25:14 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-X0iKpB/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3728)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1640)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:24:48,815 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-424:null) Unable to clean up VBD due to 
You gave an invalid object reference.  The object may have recently been deleted.  The class parameter gives the type of reference given, and the handle parameter echoes the bad value given.
	at com.xensource.xenapi.Types.checkResponse(Types.java:209)
	at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
	at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
	at com.xensource.xenapi.VBD.unplug(VBD.java:1059)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1391)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1714)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:24:48,829 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-424:null) Unable to clean up VBD due to 
You gave an invalid object reference.  The object may have recently been deleted.  The class parameter gives the type of reference given, and the handle parameter echoes the bad value given.
	at com.xensource.xenapi.Types.checkResponse(Types.java:209)
	at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
	at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
	at com.xensource.xenapi.VBD.unplug(VBD.java:1059)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1391)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1714)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:24:48,843 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-424:null) Unable to cleanup VIF
You gave an invalid object reference.  The object may have recently been deleted.  The class parameter gives the type of reference given, and the handle parameter echoes the bad value given.
	at com.xensource.xenapi.Types.checkResponse(Types.java:209)
	at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
	at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
	at com.xensource.xenapi.VIF.unplug(VIF.java:878)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1399)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1714)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:24:48,849 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-424:null) The VM is in stopped state, detected problem during startup : i-2-7-VM
2014-03-05 12:24:48,849 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-424:null) Seq 4-1156257501: Response Received: 
2014-03-05 12:24:48,851 DEBUG [agent.transport.Request] (DirectAgent-424:null) Seq 4-1156257501: Processing:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":7,"name":"i-2-7-VM","bootloader":"CD","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"Ubuntu 10.04 (32-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"3dacbe8149a1aa8f","params":{},"uuid":"0bcc3371-c51f-4988-97c3-65bc3ed1fe69","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9482e25b-bd1e-4369-9249-dd993dcd2bcd","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a298b6e6-474e-3351-b0c7-a90ef28e1989","id":2,"poolType":"NetworkFilesystem","host":"192.168.137.8","path":"/primary","port":2049}},"name":"ROOT-7","size":5368709120,"path":"7e466b68-b91b-4156-bb3c-cc3d19362fa5","volumeId":7,"vmName":"i-2-7-VM","accountId":2,"format":"VHD","id":7,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/206/206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293.iso","origUrl":"http://192.168.137.8:443/ubuntu.iso","uuid":"90395af7-e10d-446f-a58d-0c53fd548582","id":206,"format":"ISO","accountId":2,"checksum":"557231ce93ae8e98e214424cb02f8761","hvm":true,"displayText":"Ubuntu 10.04 32 bit","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.137.2/export/secondary","_role":"Image"}},"name":"206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293","guestOsType":"Ubuntu 10.04 (32-bit)","hypervisorType":"None"}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"71fa94ea-17a6-4099-b5cd-fb1b9d9866f1","ip":"192.168.137.117","netmask":"255.255.255.0","gateway":"192.168.137.1","mac":"06:85:98:00:00:6b","dns1":"192.168.137.1","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"result":false,"details":"Unable to start i-2-7-VM due to ","wait":0}}] }
2014-03-05 12:24:48,851 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257501: Received:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, { StartAnswer } }
2014-03-05 12:24:48,851 DEBUG [agent.manager.AgentAttache] (DirectAgent-424:null) Seq 4-1156257501: No more commands found
2014-03-05 12:24:48,964 INFO  [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Unable to start VM on Host[-4-Routing] due to Unable to start i-2-7-VM due to 
2014-03-05 12:24:49,056 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Cleaning up resources for the vm VM[User|UbuntuISO] in Starting state
2014-03-05 12:24:49,058 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257502: Sending  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-7-VM","wait":0}}] }
2014-03-05 12:24:49,058 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257502: Executing:  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-7-VM","wait":0}}] }
2014-03-05 12:24:49,058 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-278:null) Seq 4-1156257502: Executing request
2014-03-05 12:24:49,140 INFO  [xen.resource.CitrixResourceBase] (DirectAgent-278:null) VM does not exist on XenServer37ec4c80-1b2f-46ab-ad12-9aa1ae625241
2014-03-05 12:24:49,140 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-278:null) Seq 4-1156257502: Response Received: 
2014-03-05 12:24:49,140 DEBUG [agent.transport.Request] (DirectAgent-278:null) Seq 4-1156257502: Processing:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM does not exist","wait":0}}] }
2014-03-05 12:24:49,141 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257502: Received:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, { StopAnswer } }
2014-03-05 12:24:49,141 DEBUG [agent.manager.AgentAttache] (DirectAgent-278:null) Seq 4-1156257502: No more commands found
2014-03-05 12:24:49,155 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Changing active number of nics for network id=204 on -1
2014-03-05 12:24:49,243 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Asking VirtualRouter to release Nic[14-7-e24f0063-528a-4f4b-9119-0a27bce2911c-192.168.137.117]
2014-03-05 12:24:49,246 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Asking SecurityGroupProvider to release Nic[14-7-e24f0063-528a-4f4b-9119-0a27bce2911c-192.168.137.117]
2014-03-05 12:24:49,246 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Successfully released network resources for the vm VM[User|UbuntuISO]
2014-03-05 12:24:49,246 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Successfully cleanued up resources for the vm VM[User|UbuntuISO] in Starting state
2014-03-05 12:24:49,249 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Root volume is ready, need to place VM in volume's cluster
2014-03-05 12:24:49,256 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Deploy avoids pods: [], clusters: [], hosts: [4]
2014-03-05 12:24:49,257 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_691b6f1d@149675a1
2014-03-05 12:24:49,257 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 500, requested ram: 536870912
2014-03-05 12:24:49,257 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Is ROOT volume READY (pool already allocated)?: Yes
2014-03-05 12:24:49,257 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) DeploymentPlan has host_id specified, choosing this host and making no checks on this host: 4
2014-03-05 12:24:49,259 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) The specified host is in avoid set
2014-03-05 12:24:49,259 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Cannnot deploy to specified host, returning.
2014-03-05 12:24:49,381 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===START===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002489380
2014-03-05 12:24:49,431 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 4
2014-03-05 12:24:49,436 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Hosts's actual total CPU: 6384 and CPU after applying overprovisioning: 6384
2014-03-05 12:24:49,437 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Hosts's actual total RAM: 2693242944 and RAM after applying overprovisioning: 2693242880
2014-03-05 12:24:49,437 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) release cpu from host: 4, old used: 2000,reserved: 0, actual total: 6384, total with overprovisioning: 6384; new used: 1500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-03-05 12:24:49,437 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) release mem from host: 4, old used: 2013265920,reserved: 0, total: 2693242880; new used: 1476395008,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-03-05 12:24:49,504 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===END===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002489380
2014-03-05 12:24:49,722 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) 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
2014-03-05 12:24:49,722 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Successfully transitioned to start state for VM[User|UbuntuISO] reservation id = d6fe52f7-72a8-462e-954a-5a7cb877179e
2014-03-05 12:24:49,850 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Trying to deploy VM, vm has dcId: 1 and podId: 1
2014-03-05 12:24:49,850 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Deploy avoids pods: [], clusters: [], hosts: [4]
2014-03-05 12:24:49,853 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Root volume is ready, need to place VM in volume's cluster
2014-03-05 12:24:49,853 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Vol[7|vm=7|ROOT] is READY, changing deployment plan to use this pool's dcId: 1 , podId: 1 , and clusterId: 1
2014-03-05 12:24:49,861 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Deploy avoids pods: [], clusters: [], hosts: [4]
2014-03-05 12:24:49,862 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_691b6f1d@149675a1
2014-03-05 12:24:49,862 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 500, requested ram: 536870912
2014-03-05 12:24:49,862 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Is ROOT volume READY (pool already allocated)?: Yes
2014-03-05 12:24:49,862 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Searching resources only under specified Cluster: 1
2014-03-05 12:24:49,875 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking resources in Cluster: 1 under Pod: 1
2014-03-05 12:24:49,875 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  cluster:1
2014-03-05 12:24:49,881 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) FirstFitAllocator has 2 hosts to check for allocation: [Host[-1-Routing], Host[-4-Routing]]
2014-03-05 12:24:49,884 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Found 2 hosts for allocation after prioritization: [Host[-1-Routing], Host[-4-Routing]]
2014-03-05 12:24:49,885 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2014-03-05 12:24:49,891 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 500 and requested RAM: 536870912 , cpuOverprovisioningFactor: 1.0
2014-03-05 12:24:49,895 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Hosts's actual total CPU: 6384 and CPU after applying overprovisioning: 6384
2014-03-05 12:24:49,895 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Free CPU: 5884 , Requested CPU: 500
2014-03-05 12:24:49,895 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Free RAM: 2156371968 , Requested RAM: 536870912
2014-03-05 12:24:49,895 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-03-05 12:24:49,895 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 500, reserved: 0, actual total: 6384, total with overprovisioning: 6384; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-05 12:24:49,895 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 536870912, reserved: 0, total: 2693242880; requested mem: 536870912,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-05 12:24:49,895 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2014-03-05 12:24:49,895 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Host name: xenserver-gjhxstnz, hostId: 4 is in avoid set, skipping this and trying other available hosts
2014-03-05 12:24:49,895 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
2014-03-05 12:24:49,897 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking suitable pools for volume (Id, Type): (7,ROOT)
2014-03-05 12:24:49,897 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Volume has pool already allocated, checking if pool can be reused, poolId: 2
2014-03-05 12:24:49,899 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Planner need not allocate a pool for this volume since its READY
2014-03-05 12:24:49,899 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2014-03-05 12:24:49,899 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking if host: 1 can access any suitable storage pool for volume: ROOT
2014-03-05 12:24:49,900 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Host: 1 can access pool: 2
2014-03-05 12:24:49,902 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Found a potential host id: 1 name: xenserver-xrdcvbnu and associated storage pools for this VM
2014-03-05 12:24:49,904 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage()]
2014-03-05 12:24:49,904 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Deployment found  - P0=VM[User|UbuntuISO], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage()]
2014-03-05 12:24:50,009 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 1 host id before state transition: null
2014-03-05 12:24:50,014 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Hosts's actual total CPU: 6384 and CPU after applying overprovisioning: 6384
2014-03-05 12:24:50,015 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) We are allocating VM, increasing the used capacity of this host:1
2014-03-05 12:24:50,015 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Current Used CPU: 500 , Free CPU:5884 ,Requested CPU: 500
2014-03-05 12:24:50,015 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Current Used RAM: 536870912 , Free RAM:2156371968 ,Requested RAM: 536870912
2014-03-05 12:24:50,015 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) CPU STATS after allocation: for host: 1, old used: 500, old reserved: 0, actual total: 6384, total with overprovisioning: 6384; new used:1000, reserved:0; requested cpu:500,alloc_from_last:false
2014-03-05 12:24:50,015 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) RAM STATS after allocation: for host: 1, old used: 536870912, old reserved: 0, total: 2693242880; new used: 1073741824, reserved: 0; requested mem: 536870912,alloc_from_last:false
2014-03-05 12:24:50,084 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) VM is being created in podId: 1
2014-03-05 12:24:50,090 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Network id=204 is already implemented
2014-03-05 12:24:50,174 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Changing active number of nics for network id=204 on 1
2014-03-05 12:24:50,245 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Asking VirtualRouter to prepare for Nic[14-7-d6fe52f7-72a8-462e-954a-5a7cb877179e-192.168.137.117]
2014-03-05 12:24:50,251 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Lock is acquired for network id 204 as a part of router startup in Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage()]
2014-03-05 12:24:50,253 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Lock is released for network id 204 as a part of router startup in Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage()]
2014-03-05 12:24:50,271 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Applying dhcp entry in network Ntwk[204|Guest|6]
2014-03-05 12:24:50,287 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257503: Sending  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"06:85:98:00:00:6b","vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","defaultRouter":"192.168.137.1","defaultDns":"192.168.137.114","duid":"00:03:00:01:06:85:98:00:00:6b","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.name":"r-4-VM","router.ip":"169.254.0.208"},"wait":0}}] }
2014-03-05 12:24:50,287 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257503: Executing:  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"06:85:98:00:00:6b","vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","defaultRouter":"192.168.137.1","defaultDns":"192.168.137.114","duid":"00:03:00:01:06:85:98:00:00:6b","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.name":"r-4-VM","router.ip":"169.254.0.208"},"wait":0}}] }
2014-03-05 12:24:50,287 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-472:null) Seq 4-1156257503: Executing request
2014-03-05 12:24:50,832 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-226:null) Seq 4-1156251654: Executing request
2014-03-05 12:24:51,093 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-226:null) Seq 4-1156251654: Response Received: 
2014-03-05 12:24:51,093 DEBUG [agent.transport.Request] (DirectAgent-226:null) Seq 4-1156251654: Processing:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] }
2014-03-05 12:24:52,381 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===START===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002492379
2014-03-05 12:24:52,493 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===END===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002492379
2014-03-05 12:24:52,732 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-472:null) Seq 4-1156257503: Response Received: 
2014-03-05 12:24:52,732 DEBUG [agent.transport.Request] (DirectAgent-472:null) Seq 4-1156257503: Processing:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
2014-03-05 12:24:52,732 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257503: Received:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, { Answer } }
2014-03-05 12:24:52,732 DEBUG [agent.manager.AgentAttache] (DirectAgent-472:null) Seq 4-1156257503: No more commands found
2014-03-05 12:24:52,740 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Applying userdata and password entry in network Ntwk[204|Guest|6]
2014-03-05 12:24:52,751 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257504: Sending  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.ip":"169.254.0.208","router.name":"r-4-VM"},"wait":0}},{"com.cloud.agent.api.routing.VmDataCommand":{"vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.ip":"169.254.0.208","router.name":"r-4-VM"},"wait":0}}] }
2014-03-05 12:24:52,751 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257504: Executing:  { Cmd , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.ip":"169.254.0.208","router.name":"r-4-VM"},"wait":0}},{"com.cloud.agent.api.routing.VmDataCommand":{"vmIpAddress":"192.168.137.117","vmName":"UbuntuISO","executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.137.114","zone.network.type":"Basic","router.ip":"169.254.0.208","router.name":"r-4-VM"},"wait":0}}] }
2014-03-05 12:24:52,752 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-445:null) Seq 4-1156257504: Executing request
2014-03-05 12:24:53,584 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-445:null) Seq 4-1156257504: Response Received: 
2014-03-05 12:24:53,584 DEBUG [agent.transport.Request] (DirectAgent-445:null) Seq 4-1156257504: Processing:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}},{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
2014-03-05 12:24:53,584 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 4-1156257504: Received:  { Ans: , MgmtId: 75006878169638, via: 4, Ver: v1, Flags: 110, { Answer, Answer } }
2014-03-05 12:24:53,584 DEBUG [agent.manager.AgentAttache] (DirectAgent-445:null) Seq 4-1156257504: No more commands found
2014-03-05 12:24:53,588 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Asking SecurityGroupProvider to prepare for Nic[14-7-d6fe52f7-72a8-462e-954a-5a7cb877179e-192.168.137.117]
2014-03-05 12:24:53,598 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking if we need to prepare 1 volumes for VM[User|UbuntuISO]
2014-03-05 12:24:53,598 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) No need to recreate the volume: Vol[7|vm=7|ROOT], since it already has a pool assigned: 2, adding disk to VM
2014-03-05 12:24:53,617 DEBUG [storage.image.TemplateDataFactoryImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) template 206 is already in store:1, type:Image
2014-03-05 12:24:53,725 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 1-1024332354: Sending  { Cmd , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StartCommand":{"vm":{"id":7,"name":"i-2-7-VM","bootloader":"CD","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"Ubuntu 10.04 (32-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"3dacbe8149a1aa8f","params":{"Message.ReservedCapacityFreed.Flag":"false"},"uuid":"0bcc3371-c51f-4988-97c3-65bc3ed1fe69","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9482e25b-bd1e-4369-9249-dd993dcd2bcd","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a298b6e6-474e-3351-b0c7-a90ef28e1989","id":2,"poolType":"NetworkFilesystem","host":"192.168.137.8","path":"/primary","port":2049}},"name":"ROOT-7","size":5368709120,"path":"7e466b68-b91b-4156-bb3c-cc3d19362fa5","volumeId":7,"vmName":"i-2-7-VM","accountId":2,"format":"VHD","id":7,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/206/206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293.iso","origUrl":"http://192.168.137.8:443/ubuntu.iso","uuid":"90395af7-e10d-446f-a58d-0c53fd548582","id":206,"format":"ISO","accountId":2,"checksum":"557231ce93ae8e98e214424cb02f8761","hvm":true,"displayText":"Ubuntu 10.04 32 bit","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.137.2/export/secondary","_role":"Image"}},"name":"206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293","guestOsType":"Ubuntu 10.04 (32-bit)","hypervisorType":"None"}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"71fa94ea-17a6-4099-b5cd-fb1b9d9866f1","ip":"192.168.137.117","netmask":"255.255.255.0","gateway":"192.168.137.1","mac":"06:85:98:00:00:6b","dns1":"192.168.137.1","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"hostIp":"192.168.137.5","executeInSequence":true,"wait":0}}] }
2014-03-05 12:24:53,725 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 1-1024332354: Executing:  { Cmd , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StartCommand":{"vm":{"id":7,"name":"i-2-7-VM","bootloader":"CD","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"Ubuntu 10.04 (32-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"3dacbe8149a1aa8f","params":{"Message.ReservedCapacityFreed.Flag":"false"},"uuid":"0bcc3371-c51f-4988-97c3-65bc3ed1fe69","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9482e25b-bd1e-4369-9249-dd993dcd2bcd","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a298b6e6-474e-3351-b0c7-a90ef28e1989","id":2,"poolType":"NetworkFilesystem","host":"192.168.137.8","path":"/primary","port":2049}},"name":"ROOT-7","size":5368709120,"path":"7e466b68-b91b-4156-bb3c-cc3d19362fa5","volumeId":7,"vmName":"i-2-7-VM","accountId":2,"format":"VHD","id":7,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/206/206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293.iso","origUrl":"http://192.168.137.8:443/ubuntu.iso","uuid":"90395af7-e10d-446f-a58d-0c53fd548582","id":206,"format":"ISO","accountId":2,"checksum":"557231ce93ae8e98e214424cb02f8761","hvm":true,"displayText":"Ubuntu 10.04 32 bit","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.137.2/export/secondary","_role":"Image"}},"name":"206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293","guestOsType":"Ubuntu 10.04 (32-bit)","hypervisorType":"None"}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"71fa94ea-17a6-4099-b5cd-fb1b9d9866f1","ip":"192.168.137.117","netmask":"255.255.255.0","gateway":"192.168.137.1","mac":"06:85:98:00:00:6b","dns1":"192.168.137.1","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"hostIp":"192.168.137.5","executeInSequence":true,"wait":0}}] }
2014-03-05 12:24:53,726 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-356:null) Seq 1-1024332354: Executing request
2014-03-05 12:24:53,901 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-356:null) 1. The VM i-2-7-VM is in Starting state.
2014-03-05 12:24:53,952 DEBUG [xen.resource.XenServer56FP1Resource] (DirectAgent-356:null) Created VM 261ee011-1988-f5dc-b4be-5a34f022ffd2 for i-2-7-VM
2014-03-05 12:24:54,009 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-356:null) VBD 71563b14-8af7-9b51-5a91-13972c623f81 created for com.cloud.agent.api.to.DiskTO@51aa8c39
2014-03-05 12:24:54,479 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:null) SeqA 3-21487: Processing Seq 3-21487:  { Cmd , MgmtId: -1, via: 3, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n  \"connections\": []\n}","wait":0}}] }
2014-03-05 12:24:54,565 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:null) SeqA 3-21487: Sending Seq 3-21487:  { Ans: , MgmtId: 75006878169638, via: 3, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-03-05 12:24:55,383 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===START===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002495380
2014-03-05 12:24:55,500 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===END===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002495380
2014-03-05 12:24:58,384 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null) ===START===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002498382
2014-03-05 12:24:58,490 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null) ===END===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002498382
2014-03-05 12:25:01,383 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===START===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002501380
2014-03-05 12:25:01,497 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===END===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002501380
2014-03-05 12:25:04,383 DEBUG [cloud.api.ApiServlet] (catalina-exec-13:null) ===START===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002504380
2014-03-05 12:25:04,478 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-12:null) SeqA 3-21488: Processing Seq 3-21488:  { Cmd , MgmtId: -1, via: 3, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n  \"connections\": []\n}","wait":0}}] }
2014-03-05 12:25:04,502 DEBUG [cloud.api.ApiServlet] (catalina-exec-13:null) ===END===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002504380
2014-03-05 12:25:04,600 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-12:null) SeqA 3-21488: Sending Seq 3-21488:  { Ans: , MgmtId: 75006878169638, via: 3, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-03-05 12:25:04,985 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-356:null) VBD f026dcb6-1fd3-4905-fe36-9402676168d3 created for com.cloud.agent.api.to.DiskTO@71bd848
2014-03-05 12:25:04,986 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-356:null) Creating VIF for i-2-7-VM on nic [Nic:Guest-192.168.137.117-vlan://untagged]
2014-03-05 12:25:05,024 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-356:null) Created a vif 6e0a290e-eecc-9158-8520-adbb392436ff on 0
2014-03-05 12:25:06,063 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2014-03-05 12:25:06,234 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
2014-03-05 12:25:07,383 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null) ===START===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002507380
2014-03-05 12:25:07,478 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null) ===END===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002507380
2014-03-05 12:25:07,727 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 
2014-03-05 12:25:07,728 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 
2014-03-05 12:25:07,791 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 
2014-03-05 12:25:07,793 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 
2014-03-05 12:25:10,112 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-356:null) Task failed! Task record:                 uuid: a2afe3db-b474-a481-3532-a63cb0877881
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:30 IST 2014
            finished: Wed Mar 05 12:24:03 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-xGhat4/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

2014-03-05 12:25:10,120 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-356:null) Unable to start VM(i-2-7-VM) on host(c2d3ab1e-4e6a-42cb-85a9-5513be91d1a9) due to Task failed! Task record:                 uuid: a2afe3db-b474-a481-3532-a63cb0877881
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:30 IST 2014
            finished: Wed Mar 05 12:24:03 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-xGhat4/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

Task failed! Task record:                 uuid: a2afe3db-b474-a481-3532-a63cb0877881
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:30 IST 2014
            finished: Wed Mar 05 12:24:03 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-xGhat4/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3605)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3717)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1640)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:25:10,128 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-356:null) Catch Exception: class com.cloud.utils.exception.CloudRuntimeException due to com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(i-2-7-VM) on host(c2d3ab1e-4e6a-42cb-85a9-5513be91d1a9) due to Task failed! Task record:                 uuid: a2afe3db-b474-a481-3532-a63cb0877881
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:30 IST 2014
            finished: Wed Mar 05 12:24:03 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-xGhat4/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(i-2-7-VM) on host(c2d3ab1e-4e6a-42cb-85a9-5513be91d1a9) due to Task failed! Task record:                 uuid: a2afe3db-b474-a481-3532-a63cb0877881
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:30 IST 2014
            finished: Wed Mar 05 12:24:03 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-xGhat4/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3728)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1640)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:25:10,129 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-356:null) Unable to start i-2-7-VM due to 
com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(i-2-7-VM) on host(c2d3ab1e-4e6a-42cb-85a9-5513be91d1a9) due to Task failed! Task record:                 uuid: a2afe3db-b474-a481-3532-a63cb0877881
           nameLabel: Async.VM.start_on
     nameDescription: 
   allowedOperations: []
   currentOperations: {}
             created: Wed Mar 05 12:25:30 IST 2014
            finished: Wed Mar 05 12:24:03 IST 2014
              status: failure
          residentOn: com.xensource.xenapi.Host@ae2d2e64
            progress: 1.0
                type: <none/>
              result: 
           errorInfo: [INVALID_SOURCE, Unable to access a required file in the specified repository: file:///tmp/cdrom-repo-xGhat4/install.386/xen/vmlinuz., ]
         otherConfig: {}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3728)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1640)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:25:10,189 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-356:null) Unable to clean up VBD due to 
You gave an invalid object reference.  The object may have recently been deleted.  The class parameter gives the type of reference given, and the handle parameter echoes the bad value given.
	at com.xensource.xenapi.Types.checkResponse(Types.java:209)
	at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
	at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
	at com.xensource.xenapi.VBD.unplug(VBD.java:1059)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1391)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1714)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:25:10,202 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-356:null) Unable to clean up VBD due to 
You gave an invalid object reference.  The object may have recently been deleted.  The class parameter gives the type of reference given, and the handle parameter echoes the bad value given.
	at com.xensource.xenapi.Types.checkResponse(Types.java:209)
	at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
	at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
	at com.xensource.xenapi.VBD.unplug(VBD.java:1059)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1391)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1714)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:25:10,216 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-356:null) Unable to cleanup VIF
You gave an invalid object reference.  The object may have recently been deleted.  The class parameter gives the type of reference given, and the handle parameter echoes the bad value given.
	at com.xensource.xenapi.Types.checkResponse(Types.java:209)
	at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
	at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
	at com.xensource.xenapi.VIF.unplug(VIF.java:878)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1399)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1714)
	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:557)
	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
	at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
	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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:25:10,223 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-356:null) The VM is in stopped state, detected problem during startup : i-2-7-VM
2014-03-05 12:25:10,223 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-356:null) Seq 1-1024332354: Response Received: 
2014-03-05 12:25:10,224 DEBUG [agent.transport.Request] (DirectAgent-356:null) Seq 1-1024332354: Processing:  { Ans: , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":7,"name":"i-2-7-VM","bootloader":"CD","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"Ubuntu 10.04 (32-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"3dacbe8149a1aa8f","params":{"Message.ReservedCapacityFreed.Flag":"false"},"uuid":"0bcc3371-c51f-4988-97c3-65bc3ed1fe69","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9482e25b-bd1e-4369-9249-dd993dcd2bcd","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a298b6e6-474e-3351-b0c7-a90ef28e1989","id":2,"poolType":"NetworkFilesystem","host":"192.168.137.8","path":"/primary","port":2049}},"name":"ROOT-7","size":5368709120,"path":"7e466b68-b91b-4156-bb3c-cc3d19362fa5","volumeId":7,"vmName":"i-2-7-VM","accountId":2,"format":"VHD","id":7,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/206/206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293.iso","origUrl":"http://192.168.137.8:443/ubuntu.iso","uuid":"90395af7-e10d-446f-a58d-0c53fd548582","id":206,"format":"ISO","accountId":2,"checksum":"557231ce93ae8e98e214424cb02f8761","hvm":true,"displayText":"Ubuntu 10.04 32 bit","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.137.2/export/secondary","_role":"Image"}},"name":"206-2-03d76978-7341-3b62-bb80-3e0b3b2d2293","guestOsType":"Ubuntu 10.04 (32-bit)","hypervisorType":"None"}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"71fa94ea-17a6-4099-b5cd-fb1b9d9866f1","ip":"192.168.137.117","netmask":"255.255.255.0","gateway":"192.168.137.1","mac":"06:85:98:00:00:6b","dns1":"192.168.137.1","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"result":false,"details":"Unable to start i-2-7-VM due to ","wait":0}}] }
2014-03-05 12:25:10,224 DEBUG [agent.manager.AgentAttache] (DirectAgent-356:null) Seq 1-1024332354: No more commands found
2014-03-05 12:25:10,224 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 1-1024332354: Received:  { Ans: , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 110, { StartAnswer } }
2014-03-05 12:25:10,314 INFO  [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Unable to start VM on Host[-1-Routing] due to Unable to start i-2-7-VM due to 
2014-03-05 12:25:10,382 DEBUG [cloud.api.ApiServlet] (catalina-exec-21:null) ===START===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002510380
2014-03-05 12:25:10,397 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Cleaning up resources for the vm VM[User|UbuntuISO] in Starting state
2014-03-05 12:25:10,398 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 1-1024332355: Sending  { Cmd , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-7-VM","wait":0}}] }
2014-03-05 12:25:10,398 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 1-1024332355: Executing:  { Cmd , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-7-VM","wait":0}}] }
2014-03-05 12:25:10,399 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-133:null) Seq 1-1024332355: Executing request
2014-03-05 12:25:10,485 DEBUG [cloud.api.ApiServlet] (catalina-exec-21:null) ===END===  192.168.137.2 -- GET  command=queryAsyncJobResult&jobId=b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1&response=json&sessionkey=DbBSRYf0DUMIlbu%2BYmmG%2FoUXm78%3D&_=1394002510380
2014-03-05 12:25:10,563 INFO  [xen.resource.CitrixResourceBase] (DirectAgent-133:null) VM does not exist on XenServerc2d3ab1e-4e6a-42cb-85a9-5513be91d1a9
2014-03-05 12:25:10,563 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-133:null) Seq 1-1024332355: Response Received: 
2014-03-05 12:25:10,563 DEBUG [agent.transport.Request] (DirectAgent-133:null) Seq 1-1024332355: Processing:  { Ans: , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM does not exist","wait":0}}] }
2014-03-05 12:25:10,563 DEBUG [agent.transport.Request] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Seq 1-1024332355: Received:  { Ans: , MgmtId: 75006878169638, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2014-03-05 12:25:10,563 DEBUG [agent.manager.AgentAttache] (DirectAgent-133:null) Seq 1-1024332355: No more commands found
2014-03-05 12:25:10,579 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Changing active number of nics for network id=204 on -1
2014-03-05 12:25:10,667 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Asking VirtualRouter to release Nic[14-7-d6fe52f7-72a8-462e-954a-5a7cb877179e-192.168.137.117]
2014-03-05 12:25:10,671 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Asking SecurityGroupProvider to release Nic[14-7-d6fe52f7-72a8-462e-954a-5a7cb877179e-192.168.137.117]
2014-03-05 12:25:10,671 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Successfully released network resources for the vm VM[User|UbuntuISO]
2014-03-05 12:25:10,671 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Successfully cleanued up resources for the vm VM[User|UbuntuISO] in Starting state
2014-03-05 12:25:10,674 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Root volume is ready, need to place VM in volume's cluster
2014-03-05 12:25:10,675 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Vol[7|vm=7|ROOT] is READY, changing deployment plan to use this pool's dcId: 1 , podId: 1 , and clusterId: 1
2014-03-05 12:25:10,681 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Deploy avoids pods: [], clusters: [], hosts: [1, 4]
2014-03-05 12:25:10,682 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_691b6f1d@149675a1
2014-03-05 12:25:10,682 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 500, requested ram: 536870912
2014-03-05 12:25:10,682 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Is ROOT volume READY (pool already allocated)?: Yes
2014-03-05 12:25:10,682 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Searching resources only under specified Cluster: 1
2014-03-05 12:25:10,687 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Checking resources in Cluster: 1 under Pod: 1
2014-03-05 12:25:10,687 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  cluster:1
2014-03-05 12:25:10,690 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) FirstFitAllocator has 2 hosts to check for allocation: [Host[-4-Routing], Host[-1-Routing]]
2014-03-05 12:25:10,692 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Found 2 hosts for allocation after prioritization: [Host[-4-Routing], Host[-1-Routing]]
2014-03-05 12:25:10,692 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2014-03-05 12:25:10,692 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Host name: xenserver-gjhxstnz, hostId: 4 is in avoid set, skipping this and trying other available hosts
2014-03-05 12:25:10,692 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Host name: xenserver-xrdcvbnu, hostId: 1 is in avoid set, skipping this and trying other available hosts
2014-03-05 12:25:10,692 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ] FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2014-03-05 12:25:10,692 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) No suitable hosts found
2014-03-05 12:25:10,692 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) No suitable hosts found under this Cluster: 1
2014-03-05 12:25:10,695 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Could not find suitable Deployment Destination for this VM under any clusters, returning. 
2014-03-05 12:25:10,695 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Searching resources only under specified Cluster: 1
2014-03-05 12:25:10,695 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) The specified cluster is in avoid set, returning.
2014-03-05 12:25:10,699 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Deploy avoids pods: [], clusters: [1], hosts: [1, 4]
2014-03-05 12:25:10,700 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_691b6f1d@149675a1
2014-03-05 12:25:10,700 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 536870912
2014-03-05 12:25:10,700 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Is ROOT volume READY (pool already allocated)?: No
2014-03-05 12:25:10,700 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Searching resources only under specified Pod: 1
2014-03-05 12:25:10,700 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2014-03-05 12:25:10,702 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Removing from the clusterId list these clusters from avoid set: [1]
2014-03-05 12:25:10,702 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2014-03-05 12:25:10,923 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) 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
2014-03-05 12:25:10,928 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Hosts's actual total CPU: 6384 and CPU after applying overprovisioning: 6384
2014-03-05 12:25:10,928 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Hosts's actual total RAM: 2693242944 and RAM after applying overprovisioning: 2693242880
2014-03-05 12:25:10,928 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) release cpu from host: 1, old used: 1000,reserved: 0, actual total: 6384, total with overprovisioning: 6384; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-03-05 12:25:10,928 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) release mem from host: 1, old used: 1073741824,reserved: 0, total: 2693242880; new used: 536870912,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-03-05 12:25:11,101 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Destroying vm VM[User|UbuntuISO] as it failed to create on Host with Id:null
2014-03-05 12:25:11,266 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) 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
2014-03-05 12:25:11,449 WARN  [apache.cloudstack.alerts] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ])  alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null // message:: Failed to deploy Vm with Id: 7, on Host with Id: null
2014-03-05 12:25:11,867 INFO  [user.vm.DeployVMCmd] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|UbuntuISO]Scope=interface com.cloud.dc.DataCenter; id=1
2014-03-05 12:25:11,867 INFO  [user.vm.DeployVMCmd] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Unable to create a deployment for VM[User|UbuntuISO]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|UbuntuISO]Scope=interface com.cloud.dc.DataCenter; id=1
	at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
	at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
	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:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
2014-03-05 12:25:11,869 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-18:job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ]) Complete async job-25 = [ b2e54002-b7f9-440a-92f0-ba2e6ffa1bc1 ], jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable to create a deployment for VM[User|UbuntuISO]




Regards,
Deepak Sihag


-----Original Message-----
From: Nitin Mehta [mailto:Nitin.Mehta@citrix.com] 
Sent: Wednesday, March 05, 2014 5:25 AM
To: users@cloudstack.apache.org
Cc: Deepak Sihag
Subject: Re: Can we boot a vm with a ubuntu 10.04 iso

Indeed logs will help. But apart from that do also google a bit, as I recall seeing these issues reported before.
Generally its to do with the guest os and hypervisor capabilities if my memory serves me right.

Thanks,
-Nitin

On 04/03/14 1:50 PM, "Marty Sweet" <ms...@gmail.com> wrote:

>Hi,
>
>This is possible, could you let us know what error is being returned?
>A copy + paste of the cloudstack management server log will also be ideal.
>
>Thanks,
>Marty Sweet
>
>On 4 March 2014 07:59, Deepak Sihag <De...@infosys.com> wrote:
>> Hi Team,
>>
>> I am trying to boot a VM using an ISO of Ubuntu 10.04 provided by 
>>Ubuntu community. I have register the iso but when I am trying to 
>>launch an Instance it gives error.
>> I have tried this with cloudstack 3.0 to 4.2 all versions. Every time 
>>the same thing. So I need our help here. First thing is it possible to 
>>have a VM with GUI. If yes then how can I use Ubuntu iso.
>>
>> Regards,
>> Deepak Sihag
>>
>>
>>
>> **************** CAUTION - Disclaimer *****************  This e-mail 
>>contains PRIVILEGED AND CONFIDENTIAL INFORMATION intended solely  for 
>>the use of the addressee(s). If you are not the intended recipient, 
>>please  notify the sender by e-mail and delete the original message. 
>>Further, you are not  to copy, disclose, or distribute this e-mail or 
>>its contents to any other person and  any such actions are unlawful. 
>>This e-mail may contain viruses. Infosys has taken  every reasonable 
>>precaution to minimize this risk, but is not liable for any damage  
>>you may sustain as a result of any virus in this e-mail. You should 
>>carry out your  own virus checks before opening the e-mail or 
>>attachment. Infosys reserves the  right to monitor and review the 
>>content of all messages sent to or from this e-mail  address. Messages 
>>sent to or from this e-mail address may be stored on the  Infosys 
>>e-mail system.
>> ***INFOSYS******** End of Disclaimer ********INFOSYS***


Re: Can we boot a vm with a ubuntu 10.04 iso

Posted by Nitin Mehta <Ni...@citrix.com>.
Indeed logs will help. But apart from that do also google a bit, as I
recall seeing these issues reported before.
Generally its to do with the guest os and hypervisor capabilities if my
memory serves me right.

Thanks,
-Nitin

On 04/03/14 1:50 PM, "Marty Sweet" <ms...@gmail.com> wrote:

>Hi,
>
>This is possible, could you let us know what error is being returned?
>A copy + paste of the cloudstack management server log will also be ideal.
>
>Thanks,
>Marty Sweet
>
>On 4 March 2014 07:59, Deepak Sihag <De...@infosys.com> wrote:
>> Hi Team,
>>
>> I am trying to boot a VM using an ISO of Ubuntu 10.04 provided by
>>Ubuntu community. I have register the iso but when I am trying to launch
>>an Instance it gives error.
>> I have tried this with cloudstack 3.0 to 4.2 all versions. Every time
>>the same thing. So I need our help here. First thing is it possible to
>>have a VM with GUI. If yes then how can I use Ubuntu iso.
>>
>> Regards,
>> Deepak Sihag
>>
>>
>>
>> **************** CAUTION - Disclaimer *****************
>> This e-mail contains PRIVILEGED AND CONFIDENTIAL INFORMATION intended
>>solely
>> for the use of the addressee(s). If you are not the intended recipient,
>>please
>> notify the sender by e-mail and delete the original message. Further,
>>you are not
>> to copy, disclose, or distribute this e-mail or its contents to any
>>other person and
>> any such actions are unlawful. This e-mail may contain viruses. Infosys
>>has taken
>> every reasonable precaution to minimize this risk, but is not liable
>>for any damage
>> you may sustain as a result of any virus in this e-mail. You should
>>carry out your
>> own virus checks before opening the e-mail or attachment. Infosys
>>reserves the
>> right to monitor and review the content of all messages sent to or from
>>this e-mail
>> address. Messages sent to or from this e-mail address may be stored on
>>the
>> Infosys e-mail system.
>> ***INFOSYS******** End of Disclaimer ********INFOSYS***


Re: Can we boot a vm with a ubuntu 10.04 iso

Posted by Marty Sweet <ms...@gmail.com>.
Hi,

This is possible, could you let us know what error is being returned?
A copy + paste of the cloudstack management server log will also be ideal.

Thanks,
Marty Sweet

On 4 March 2014 07:59, Deepak Sihag <De...@infosys.com> wrote:
> Hi Team,
>
> I am trying to boot a VM using an ISO of Ubuntu 10.04 provided by Ubuntu community. I have register the iso but when I am trying to launch an Instance it gives error.
> I have tried this with cloudstack 3.0 to 4.2 all versions. Every time the same thing. So I need our help here. First thing is it possible to have a VM with GUI. If yes then how can I use Ubuntu iso.
>
> Regards,
> Deepak Sihag
>
>
>
> **************** CAUTION - Disclaimer *****************
> This e-mail contains PRIVILEGED AND CONFIDENTIAL INFORMATION intended solely
> for the use of the addressee(s). If you are not the intended recipient, please
> notify the sender by e-mail and delete the original message. Further, you are not
> to copy, disclose, or distribute this e-mail or its contents to any other person and
> any such actions are unlawful. This e-mail may contain viruses. Infosys has taken
> every reasonable precaution to minimize this risk, but is not liable for any damage
> you may sustain as a result of any virus in this e-mail. You should carry out your
> own virus checks before opening the e-mail or attachment. Infosys reserves the
> right to monitor and review the content of all messages sent to or from this e-mail
> address. Messages sent to or from this e-mail address may be stored on the
> Infosys e-mail system.
> ***INFOSYS******** End of Disclaimer ********INFOSYS***