Hi, I think I found the problem. It appears that the templates based on CentOS 6.3 upward do not work. Once I created a new template based on CentOS 6.2 it worked. The question is whether this is not breaking something. The actual OS is 6.5 but when creating a template I selected 6.2 and the instances based on this template stay up while the instance based on a template that was created using OS type CentOS 6.3 or CentOS 6.4 die with the error "Can't find the guest os: CentOS 6.4 (64-bit) mapping into XCP's guestOS type, start it as HVM guest" or similar in the log. I know XCP 6.1 supports guest OS types up to CentOS 6.4 but it looks like CS 4.2.1 does not. I also saw, in my searches, a jira entry mentioning this. Was a patch applied and where can I find it?
Regards, Osay On 24 March 2014 08:20, Osay Osman Yuuni <[email protected]> wrote: > Hi, > I have a CS 4.2.1 installed with XCP 6.1 as hypervisor. I have various > templates (windows 2k12R2, CentOS 6.3, CentOS 6.5, Ubuntu 12.04.3 LTS). > I'm able to instantiate windows and Ubuntu VMs without issues but when I > instantiate the CentOS 6.3 or 6.5 VMs they just die. The VM appears in the > hypervisor and after about a minute it disappears. In the management > server GUI the VM is stopped. When I restart it, it starts but after about > a minute it stops again. I've combed through the management server log but > am unable to pin down what is causing this to happen. Is it that CentOS 6 > is unsupported (the default 5.6 template can be instantiated without > issues). > > > Below is a snippet of the management server log. The only issue I see is > the error "cannot bridge firewall", which to be honest, I don't > understand. Perhaps the more seasoned users can point out something that's > obviously causing the VM to stop? > > ======================================= > > 2014-03-24 08:04:41,048 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Hosts's > actual total CPU: 160000 and CPU after applying overprovisioning: 160000 > 2014-03-24 08:04:41,048 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) We need > to allocate to the last host again, so checking if there is enough reserved > capacity > 2014-03-24 08:04:41,048 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Reserved CPU: 0 , Requested CPU: 1500 > 2014-03-24 08:04:41,048 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Reserved RAM: 0 , Requested RAM: 1073741824 > 2014-03-24 08:04:41,048 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) STATS: > Failed to alloc resource from host: 1 reservedCpu: 0, requested cpu: 1500, > reservedMem: 0, requested mem: 1073741824 > 2014-03-24 08:04:41,049 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Host > does not have enough reserved CPU available, cannot allocate to this host. > 2014-03-24 08:04:41,049 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) The > last host of this VM does not have enough capacity > 2014-03-24 08:04:41,049 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Cannot > choose the last host to deploy this VM > 2014-03-24 08:04:41,049 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Searching resources only under specified Cluster: 1 > 2014-03-24 08:04:41,072 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Checking resources in Cluster: 1 under Pod: 1 > 2014-03-24 08:04:41,082 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1 > 2014-03-24 08:04:41,095 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for > allocation: [Host[-1-Routing]] > 2014-03-24 08:04:41,107 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) Found 1 hosts for allocation after > prioritization: [Host[-1-Routing]] > 2014-03-24 08:04:41,107 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) Looking for speed=1500Mhz, Ram=1024 > 2014-03-24 08:04:41,132 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for > requested CPU: 1500 and requested RAM: 1073741824 , > cpuOverprovisioningFactor: 1.0 > 2014-03-24 08:04:41,143 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) Hosts's actual total CPU: 160000 and CPU after > applying overprovisioning: 160000 > 2014-03-24 08:04:41,143 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) Free CPU: 157000 , Requested CPU: 1500 > 2014-03-24 08:04:41,143 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) Free RAM: 537663799296 , Requested RAM: 1073741824 > 2014-03-24 08:04:41,143 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) Host has enough CPU and RAM available > 2014-03-24 08:04:41,143 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 3000, > reserved: 0, actual total: 160000, total with overprovisioning: 160000; > requested cpu:1500,alloc_from_last_host?:false ,considerReservedCapacity?: > true > 2014-03-24 08:04:41,144 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: > 2550136832, reserved: 0, total: 540213936128; requested mem: > 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true > 2014-03-24 08:04:41,144 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) Found a suitable host, adding to list: 1 > 2014-03-24 08:04:41,144 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts > 2014-03-24 08:04:41,151 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Checking suitable pools for volume (Id, Type): (16,ROOT) > 2014-03-24 08:04:41,152 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Volume > has pool already allocated, checking if pool can be reused, poolId: 2 > 2014-03-24 08:04:41,156 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Planner > need not allocate a pool for this volume since its READY > 2014-03-24 08:04:41,157 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Checking suitable pools for volume (Id, Type): (17,DATADISK) > 2014-03-24 08:04:41,157 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Volume > has pool already allocated, checking if pool can be reused, poolId: 2 > 2014-03-24 08:04:41,161 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Planner > need not allocate a pool for this volume since its READY > 2014-03-24 08:04:41,162 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Trying > to find a potenial host and associated storage pools from the suitable > host/pool lists for this VM > 2014-03-24 08:04:41,162 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Checking if host: 1 can access any suitable storage pool for volume: ROOT > 2014-03-24 08:04:41,166 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Host: 1 > can access pool: 2 > 2014-03-24 08:04:41,166 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Checking if host: 1 can access any suitable storage pool for volume: > DATADISK > 2014-03-24 08:04:41,170 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Host: 1 > can access pool: 2 > 2014-03-24 08:04:41,174 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Found a > potential host id: 1 name: cloudsrv1.afdb.org and associated storage > pools for this VM > 2014-03-24 08:04:41,179 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > 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-24 08:04:41,233 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) VM > state transitted from :Stopped to Starting with event: StartRequestedvm's > original host id: 1 new host id: null host id before state transition: null > 2014-03-24 08:04:41,234 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Successfully transitioned to start state for > VM[User|e461c77d-9d39-43f2-94c3-79d00c36315c] reservation id = > e79b6036-20a0-4a9d-a76e-73010097026a > 2014-03-24 08:04:41,247 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Trying > to deploy VM, vm has dcId: 1 and podId: 1 > 2014-03-24 08:04:41,247 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > advanceStart: DeploymentPlan is provided, using dcId:1, podId: 1, > clusterId: 1, hostId: 1, poolId: null > 2014-03-24 08:04:41,247 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Deploy > avoids pods: null, clusters: null, hosts: null > 2014-03-24 08:04:41,259 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Root > volume is ready, need to place VM in volume's cluster > 2014-03-24 08:04:41,293 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Deploy > avoids pods: [], clusters: [], hosts: [] > 2014-03-24 08:04:41,293 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > DeploymentPlanner allocation algorithm: > com.cloud.deploy.UserDispersingPlanner_EnhancerByCloudStack_b1882cfb@554079b2 > 2014-03-24 08:04:41,293 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Trying > to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested > cpu: 1500, requested ram: 1073741824 > 2014-03-24 08:04:41,294 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Is ROOT > volume READY (pool already allocated)?: Yes > 2014-03-24 08:04:41,294 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > DeploymentPlan has host_id specified, choosing this host and making no > checks on this host: 1 > 2014-03-24 08:04:41,300 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Looking > for suitable pools for this host under zone: 1, pod: 1, cluster: 1 > 2014-03-24 08:04:41,307 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Checking suitable pools for volume (Id, Type): (16,ROOT) > 2014-03-24 08:04:41,308 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Volume > has pool already allocated, checking if pool can be reused, poolId: 2 > 2014-03-24 08:04:41,313 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Planner > need not allocate a pool for this volume since its READY > 2014-03-24 08:04:41,314 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Checking suitable pools for volume (Id, Type): (17,DATADISK) > 2014-03-24 08:04:41,314 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Volume > has pool already allocated, checking if pool can be reused, poolId: 2 > 2014-03-24 08:04:41,319 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Planner > need not allocate a pool for this volume since its READY > 2014-03-24 08:04:41,319 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Trying > to find a potenial host and associated storage pools from the suitable > host/pool lists for this VM > 2014-03-24 08:04:41,319 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Checking if host: 1 can access any suitable storage pool for volume: ROOT > 2014-03-24 08:04:41,323 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Host: 1 > can access pool: 2 > 2014-03-24 08:04:41,324 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Checking if host: 1 can access any suitable storage pool for volume: > DATADISK > 2014-03-24 08:04:41,328 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Host: 1 > can access pool: 2 > 2014-03-24 08:04:41,331 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Found a > potential host id: 1 name: cloudsrv1.afdb.org and associated storage > pools for this VM > 2014-03-24 08:04:41,335 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > 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-24 08:04:41,335 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Deployment found - P0=VM[User|e461c77d-9d39-43f2-94c3-79d00c36315c], > 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-24 08:04:41,374 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) VM > state transitted from :Starting to Starting with event: OperationRetryvm's > original host id: 1 new host id: 1 host id before state transition: null > 2014-03-24 08:04:41,382 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) VM > starting again on the last host it was stopped on > 2014-03-24 08:04:41,414 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Hosts's > actual total CPU: 160000 and CPU after applying overprovisioning: 160000 > 2014-03-24 08:04:41,415 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) We are > allocating VM, increasing the used capacity of this host:1 > 2014-03-24 08:04:41,415 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Current > Used CPU: 3000 , Free CPU:157000 ,Requested CPU: 1500 > 2014-03-24 08:04:41,415 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Current > Used RAM: 2550136832 , Free RAM:537663799296 ,Requested RAM: 1073741824 > 2014-03-24 08:04:41,415 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) We are > allocating VM to the last host again, so adjusting the reserved capacity if > it is not less than required > 2014-03-24 08:04:41,415 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Reserved CPU: 0 , Requested CPU: 1500 > 2014-03-24 08:04:41,415 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Reserved RAM: 0 , Requested RAM: 1073741824 > 2014-03-24 08:04:41,415 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) CPU > STATS after allocation: for host: 1, old used: 3000, old reserved: 0, > actual total: 160000, total with overprovisioning: 160000; new used:4500, > reserved:0; requested cpu:1500,alloc_from_last:true > 2014-03-24 08:04:41,416 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) RAM > STATS after allocation: for host: 1, old used: 2550136832, old reserved: 0, > total: 540213936128; new used: 3623878656, reserved: 0; requested mem: > 1073741824,alloc_from_last:true > 2014-03-24 08:04:41,426 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) VM is > being created in podId: 1 > 2014-03-24 08:04:41,433 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-4:null) SeqA 2-54055: Processing Seq 2-54055: { Cmd > , MgmtId: -1, via: 2, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2014-03-24 08:04:41,446 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-4:null) SeqA 2-54055: Sending Seq 2-54055: { Ans: , > MgmtId: 7063056740127, via: 2, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2014-03-24 08:04:41,464 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Network > id=204 is already implemented > 2014-03-24 08:04:41,551 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Changing active number of nics for network id=204 on 1 > 2014-03-24 08:04:41,577 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Asking > VirtualRouter to prepare for > Nic[17-10-e79b6036-20a0-4a9d-a76e-73010097026a-192.168.40.185] > 2014-03-24 08:04:41,619 DEBUG > [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-26:job-33 > = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) 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-24 08:04:41,630 DEBUG > [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-26:job-33 > = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) 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-24 08:04:41,721 DEBUG > [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-26:job-33 > = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Applying dhcp entry in network > Ntwk[204|Guest|6] > 2014-03-24 08:04:41,786 DEBUG [agent.transport.Request] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Seq > 1-212812146: Sending { Cmd , MgmtId: 7063056740127, via: 1, Ver: v1, > Flags: 100111, > [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"06:f4:a0:00:00:0e","vmIpAddress":"192.168.40.185","vmName":"e461c77d-9d39-43f2-94c3-79d00c36315c","defaultRouter":"192.168.40.1","defaultDns":"192.168.40.183","duid":"00:03:00:01:06:f4:a0:00:00:0e","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.40.183","zone.network.type":"Basic"," > router.name":"r-4-VM","router.ip":"169.254.2.80"},"wait":0}}] } > 2014-03-24 08:04:41,788 DEBUG [agent.transport.Request] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Seq > 1-212812146: Executing: { Cmd , MgmtId: 7063056740127, via: 1, Ver: v1, > Flags: 100111, > [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"06:f4:a0:00:00:0e","vmIpAddress":"192.168.40.185","vmName":"e461c77d-9d39-43f2-94c3-79d00c36315c","defaultRouter":"192.168.40.1","defaultDns":"192.168.40.183","duid":"00:03:00:01:06:f4:a0:00:00:0e","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.40.183","zone.network.type":"Basic"," > router.name":"r-4-VM","router.ip":"169.254.2.80"},"wait":0}}] } > 2014-03-24 08:04:41,789 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-377:null) Seq 1-212812146: Executing request > 2014-03-24 08:04:42,782 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-377:null) Seq 1-212812146: Response Received: > 2014-03-24 08:04:42,783 DEBUG [agent.transport.Request] > (DirectAgent-377:null) Seq 1-212812146: Processing: { Ans: , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 110, > [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } > 2014-03-24 08:04:42,784 DEBUG [agent.transport.Request] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Seq > 1-212812146: Received: { Ans: , MgmtId: 7063056740127, via: 1, Ver: v1, > Flags: 110, { Answer } } > 2014-03-24 08:04:42,784 DEBUG [agent.manager.AgentAttache] > (DirectAgent-377:null) Seq 1-212812146: No more commands found > 2014-03-24 08:04:42,824 DEBUG > [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-26:job-33 > = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Applying userdata and password > entry in network Ntwk[204|Guest|6] > 2014-03-24 08:04:42,866 DEBUG [agent.transport.Request] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Seq > 1-212812147: Sending { Cmd , MgmtId: 7063056740127, via: 1, Ver: v1, > Flags: 100111, > [{"com.cloud.agent.api.routing.VmDataCommand":{"vmIpAddress":"192.168.40.185","vmName":"e461c77d-9d39-43f2-94c3-79d00c36315c","executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.40.183","zone.network.type":"Basic","router.ip":"169.254.2.80"," > router.name":"r-4-VM"},"wait":0}}] } > 2014-03-24 08:04:42,867 DEBUG [agent.transport.Request] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Seq > 1-212812147: Executing: { Cmd , MgmtId: 7063056740127, via: 1, Ver: v1, > Flags: 100111, > [{"com.cloud.agent.api.routing.VmDataCommand":{"vmIpAddress":"192.168.40.185","vmName":"e461c77d-9d39-43f2-94c3-79d00c36315c","executeInSequence":true,"accessDetails":{"router.guest.ip":"192.168.40.183","zone.network.type":"Basic","router.ip":"169.254.2.80"," > router.name":"r-4-VM"},"wait":0}}] } > 2014-03-24 08:04:42,868 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-264:null) Seq 1-212812147: Executing request > 2014-03-24 08:04:43,627 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-264:null) Seq 1-212812147: Response Received: > 2014-03-24 08:04:43,628 DEBUG [agent.transport.Request] > (DirectAgent-264:null) Seq 1-212812147: Processing: { Ans: , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 110, > [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } > 2014-03-24 08:04:43,629 DEBUG [agent.manager.AgentAttache] > (DirectAgent-264:null) Seq 1-212812147: No more commands found > 2014-03-24 08:04:43,629 DEBUG [agent.transport.Request] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Seq > 1-212812147: Received: { Ans: , MgmtId: 7063056740127, via: 1, Ver: v1, > Flags: 110, { Answer } } > 2014-03-24 08:04:43,640 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Asking > SecurityGroupProvider to prepare for > Nic[17-10-e79b6036-20a0-4a9d-a76e-73010097026a-192.168.40.185] > 2014-03-24 08:04:43,672 DEBUG [cloud.storage.VolumeManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Checking if we need to prepare 2 volumes for > VM[User|e461c77d-9d39-43f2-94c3-79d00c36315c] > 2014-03-24 08:04:43,672 DEBUG [cloud.storage.VolumeManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) No need > to recreate the volume: Vol[16|vm=10|ROOT], since it already has a pool > assigned: 2, adding disk to VM > 2014-03-24 08:04:43,677 DEBUG [cloud.storage.VolumeManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) No need > to recreate the volume: Vol[17|vm=10|DATADISK], since it already has a pool > assigned: 2, adding disk to VM > 2014-03-24 08:04:43,801 DEBUG [cloud.api.ApiServlet] > (catalina-exec-3:null) ===START=== 10.29.128.147 -- GET > command=queryAsyncJobResult&jobId=0290d97b-4bd9-4509-8bd2-53b16b032f1b&response=json&sessionkey=bNFqqGTaBxPjbmygj7Q60bFZHOs%3D&_=1395641076709 > 2014-03-24 08:04:43,823 DEBUG [agent.transport.Request] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Seq > 1-212812148: Sending { Cmd , MgmtId: 7063056740127, via: 1, Ver: v1, > Flags: 100111, > [{"com.cloud.agent.api.StartCommand":{"vm":{"id":10,"name":"i-3-10-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":1500,"maxSpeed":1500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"CentOS > 6.4 > (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"451e1b5f3d5180af","params":{"platform":"viridian:true;acpi:1;apic:true;pae:true;nx:true;timeoffset:0","hypervisortoolsversion":"xenserver61","Message.ReservedCapacityFreed.Flag":"true"},"uuid":"e461c77d-9d39-43f2-94c3-79d00c36315c","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"f8e6b36d-b48b-42fc-a2d7-f50f922385b5","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ba737116-8aa6-3644-a595-383d4dc39ed3","id":2,"poolType":"NetworkFilesystem","host":"192.168.40.71","path":"/fs_nfs1","port":2049}},"name":"ROOT-10","size":32212254720,"path":"48e58db8-0353-411d-9777-6978a36f0c72","volumeId":16,"vmName":"i-3-10-VM","accountId":3,"format":"VHD","id":16,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"387af0d1-3996-46fe-b44c-935c18680a55","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ba737116-8aa6-3644-a595-383d4dc39ed3","id":2,"poolType":"NetworkFilesystem","host":"192.168.40.71","path":"/fs_nfs1","port":2049}},"name":"DATA-10","size":32212254720,"path":"e93ffb66-d328-47d5-87bb-e34145299354","volumeId":17,"vmName":"i-3-10-VM","accountId":3,"format":"VHD","id":17,"hypervisorType":"XenServer"}},"diskSeq":1,"type":"DATADISK"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":100,"defaultNic":true,"uuid":"c15cb1c8-9d3a-4735-8493-f8c4e3e6840d","ip":"192.168.40.185","netmask":"255.255.255.0","gateway":"192.168.40.1","mac":"06:f4:a0:00:00:0e","dns1":"192.168.40.41","dns2":"192.168.40.42","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"hostIp":"192.168.40.245","executeInSequence":true,"wait":0}}] > } > 2014-03-24 08:04:43,828 DEBUG [agent.transport.Request] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Seq > 1-212812148: Executing: { Cmd , MgmtId: 7063056740127, via: 1, Ver: v1, > Flags: 100111, > [{"com.cloud.agent.api.StartCommand":{"vm":{"id":10,"name":"i-3-10-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":1500,"maxSpeed":1500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"CentOS > 6.4 > (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"451e1b5f3d5180af","params":{"platform":"viridian:true;acpi:1;apic:true;pae:true;nx:true;timeoffset:0","hypervisortoolsversion":"xenserver61","Message.ReservedCapacityFreed.Flag":"true"},"uuid":"e461c77d-9d39-43f2-94c3-79d00c36315c","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"f8e6b36d-b48b-42fc-a2d7-f50f922385b5","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ba737116-8aa6-3644-a595-383d4dc39ed3","id":2,"poolType":"NetworkFilesystem","host":"192.168.40.71","path":"/fs_nfs1","port":2049}},"name":"ROOT-10","size":32212254720,"path":"48e58db8-0353-411d-9777-6978a36f0c72","volumeId":16,"vmName":"i-3-10-VM","accountId":3,"format":"VHD","id":16,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"387af0d1-3996-46fe-b44c-935c18680a55","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ba737116-8aa6-3644-a595-383d4dc39ed3","id":2,"poolType":"NetworkFilesystem","host":"192.168.40.71","path":"/fs_nfs1","port":2049}},"name":"DATA-10","size":32212254720,"path":"e93ffb66-d328-47d5-87bb-e34145299354","volumeId":17,"vmName":"i-3-10-VM","accountId":3,"format":"VHD","id":17,"hypervisorType":"XenServer"}},"diskSeq":1,"type":"DATADISK"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":100,"defaultNic":true,"uuid":"c15cb1c8-9d3a-4735-8493-f8c4e3e6840d","ip":"192.168.40.185","netmask":"255.255.255.0","gateway":"192.168.40.1","mac":"06:f4:a0:00:00:0e","dns1":"192.168.40.41","dns2":"192.168.40.42","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"hostIp":"192.168.40.245","executeInSequence":true,"wait":0}}] > } > 2014-03-24 08:04:43,829 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-419:null) Seq 1-212812148: Executing request > 2014-03-24 08:04:43,880 DEBUG [cloud.api.ApiServlet] > (catalina-exec-3:null) ===END=== 10.29.128.147 -- GET > command=queryAsyncJobResult&jobId=0290d97b-4bd9-4509-8bd2-53b16b032f1b&response=json&sessionkey=bNFqqGTaBxPjbmygj7Q60bFZHOs%3D&_=1395641076709 > 2014-03-24 08:04:44,001 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-419:null) 1. The VM i-3-10-VM is in Starting state. > 2014-03-24 08:04:44,013 DEBUG [xen.resource.CitrixHelper] > (DirectAgent-419:null) Can't find the guest os: CentOS 6.4 (64-bit) mapping > into XCP's guestOS type, start it as HVM guest > 2014-03-24 08:04:44,119 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-419:null) Created VM 62bb9717-c9dd-8c2c-e112-bbbb986265f3 for > i-3-10-VM > 2014-03-24 08:04:44,261 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-419:null) VBD f5c8b98c-c4ed-7fb1-6be1-a32b45e538de created for > com.cloud.agent.api.to.DiskTO@5e0fbcd0 > 2014-03-24 08:04:44,346 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-419:null) VBD 371f106e-7873-59f7-654f-afffae5224ed created for > com.cloud.agent.api.to.DiskTO@5b352bee > 2014-03-24 08:04:44,413 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-419:null) VBD 4eb822f9-f4ea-8197-c437-2e2fd39abd2a created for > com.cloud.agent.api.to.DiskTO@7fd74509 > 2014-03-24 08:04:44,413 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-419:null) Creating VIF for i-3-10-VM on nic > [Nic:Guest-192.168.40.185-vlan://untagged] > 2014-03-24 08:04:44,521 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-419:null) Created a vif 0623efa2-46f4-e3b6-7eb6-e0cbd337b588 > on 0 > 2014-03-24 08:04:46,797 DEBUG [cloud.api.ApiServlet] > (catalina-exec-7:null) ===START=== 10.29.128.147 -- GET > command=queryAsyncJobResult&jobId=0290d97b-4bd9-4509-8bd2-53b16b032f1b&response=json&sessionkey=bNFqqGTaBxPjbmygj7Q60bFZHOs%3D&_=1395641079708 > 2014-03-24 08:04:46,872 DEBUG [cloud.api.ApiServlet] > (catalina-exec-7:null) ===END=== 10.29.128.147 -- GET > command=queryAsyncJobResult&jobId=0290d97b-4bd9-4509-8bd2-53b16b032f1b&response=json&sessionkey=bNFqqGTaBxPjbmygj7Q60bFZHOs%3D&_=1395641079708 > 2014-03-24 08:04:49,797 DEBUG [cloud.api.ApiServlet] > (catalina-exec-24:null) ===START=== 10.29.128.147 -- GET > command=queryAsyncJobResult&jobId=0290d97b-4bd9-4509-8bd2-53b16b032f1b&response=json&sessionkey=bNFqqGTaBxPjbmygj7Q60bFZHOs%3D&_=1395641082708 > 2014-03-24 08:04:49,863 DEBUG [cloud.api.ApiServlet] > (catalina-exec-24:null) ===END=== 10.29.128.147 -- GET > command=queryAsyncJobResult&jobId=0290d97b-4bd9-4509-8bd2-53b16b032f1b&response=json&sessionkey=bNFqqGTaBxPjbmygj7Q60bFZHOs%3D&_=1395641082708 > 2014-03-24 08:04:50,828 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-419:null) 2. The VM i-3-10-VM is in Running state. > 2014-03-24 08:04:50,828 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-419:null) Seq 1-212812148: Response Received: > 2014-03-24 08:04:50,833 DEBUG [agent.transport.Request] > (DirectAgent-419:null) Seq 1-212812148: Processing: { Ans: , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 110, > [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":10,"name":"i-3-10-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":1500,"maxSpeed":1500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"CentOS > 6.4 > (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"451e1b5f3d5180af","params":{"platform":"viridian:true;acpi:1;apic:true;pae:true;nx:true;timeoffset:0","hypervisortoolsversion":"xenserver61","Message.ReservedCapacityFreed.Flag":"true"},"uuid":"e461c77d-9d39-43f2-94c3-79d00c36315c","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"f8e6b36d-b48b-42fc-a2d7-f50f922385b5","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ba737116-8aa6-3644-a595-383d4dc39ed3","id":2,"poolType":"NetworkFilesystem","host":"192.168.40.71","path":"/fs_nfs1","port":2049}},"name":"ROOT-10","size":32212254720,"path":"48e58db8-0353-411d-9777-6978a36f0c72","volumeId":16,"vmName":"i-3-10-VM","accountId":3,"format":"VHD","id":16,"hypervisorType":"XenServer"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"387af0d1-3996-46fe-b44c-935c18680a55","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ba737116-8aa6-3644-a595-383d4dc39ed3","id":2,"poolType":"NetworkFilesystem","host":"192.168.40.71","path":"/fs_nfs1","port":2049}},"name":"DATA-10","size":32212254720,"path":"e93ffb66-d328-47d5-87bb-e34145299354","volumeId":17,"vmName":"i-3-10-VM","accountId":3,"format":"VHD","id":17,"hypervisorType":"XenServer"}},"diskSeq":1,"type":"DATADISK"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":100,"defaultNic":true,"uuid":"c15cb1c8-9d3a-4735-8493-f8c4e3e6840d","ip":"192.168.40.185","netmask":"255.255.255.0","gateway":"192.168.40.1","mac":"06:f4:a0:00:00:0e","dns1":"192.168.40.41","dns2":"192.168.40.42","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"result":true,"wait":0}}] > } > 2014-03-24 08:04:50,834 DEBUG [agent.transport.Request] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Seq > 1-212812148: Received: { Ans: , MgmtId: 7063056740127, via: 1, Ver: v1, > Flags: 110, { StartAnswer } } > 2014-03-24 08:04:50,835 DEBUG [agent.manager.AgentAttache] > (DirectAgent-419:null) Seq 1-212812148: No more commands found > 2014-03-24 08:04:51,038 DEBUG [network.security.SecurityGroupManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Security Group Mgr v2: scheduling ruleset updates for 1 vms (unique=1), > current queue size=0 > 2014-03-24 08:04:51,050 DEBUG [network.security.SecurityGroupManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Security Group Mgr v2: done scheduling ruleset updates for 1 vms: num new > jobs=1 num rows insert or updated=1 time taken=11 > 2014-03-24 08:04:51,067 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) VM > state transitted from :Starting to Running with event: > OperationSucceededvm's original host id: 1 new host id: 1 host id before > state transition: 1 > 2014-03-24 08:04:51,076 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Start > completed for VM VM[User|e461c77d-9d39-43f2-94c3-79d00c36315c] > 2014-03-24 08:04:51,085 DEBUG [network.security.SecurityGroupManagerImpl] > (SecGrp-Worker-15:null) SecurityGroupManager v2: sending ruleset update for > vm i-3-10-VM:ingress num rules=0:egress num rules=0 num cidrs=0 > sig=d41d8cd98f00b204e9800998ecf8427e > 2014-03-24 08:04:51,099 DEBUG [agent.transport.Request] > (SecGrp-Worker-15:null) Seq 1-212812149: Sending { Cmd , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 100111, > [{"com.cloud.agent.api.SecurityGroupRulesCmd":{"guestIp":"192.168.40.185","vmName":"i-3-10-VM","guestMac":"06:f4:a0:00:00:0e","signature":"d41d8cd98f00b204e9800998ecf8427e","seqNum":3,"vmId":10,"msId":7063056740127,"ingressRuleSet":[],"egressRuleSet":[],"wait":0}}] > } > 2014-03-24 08:04:51,103 DEBUG [agent.transport.Request] > (SecGrp-Worker-15:null) Seq 1-212812149: Executing: { Cmd , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 100111, > [{"com.cloud.agent.api.SecurityGroupRulesCmd":{"guestIp":"192.168.40.185","vmName":"i-3-10-VM","guestMac":"06:f4:a0:00:00:0e","signature":"d41d8cd98f00b204e9800998ecf8427e","seqNum":3,"vmId":10,"msId":7063056740127,"ingressRuleSet":[],"egressRuleSet":[],"wait":0}}] > } > 2014-03-24 08:04:51,105 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-191:null) Seq 1-212812149: Executing request > 2014-03-24 08:04:51,171 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) > Complete async job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ], > jobStatus: 1, resultCode: 0, result: > org.apache.cloudstack.api.response.UserVmResponse@58f440c3 > 2014-03-24 08:04:51,187 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-26:job-33 = [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ]) Done > executing org.apache.cloudstack.api.command.user.vm.StartVMCmd for job-33 = > [ 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] > 2014-03-24 08:04:51,272 WARN [xen.resource.CitrixResourceBase] > (DirectAgent-191:null) Host 192.168.40.245 cannot do bridge firewalling > 2014-03-24 08:04:51,273 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-191:null) Seq 1-212812149: Response Received: > 2014-03-24 08:04:51,274 DEBUG [agent.transport.Request] > (DirectAgent-191:null) Seq 1-212812149: Processing: { Ans: , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 110, > [{"com.cloud.agent.api.SecurityGroupRuleAnswer":{"logSequenceNumber":3,"vmId":10,"reason":"CANNOT_BRIDGE_FIREWALL","result":false,"details":"Host > 192.168.40.245 cannot do bridge firewalling","wait":0}}] } > 2014-03-24 08:04:51,280 DEBUG [network.security.SecurityGroupListener] > (DirectAgent-191:null) Failed to program rule > com.cloud.agent.api.SecurityGroupRuleAnswer into host 1 due to Host > 192.168.40.245 cannot do bridge firewalling and updated jobs > 2014-03-24 08:04:51,281 DEBUG [network.security.SecurityGroupListener] > (DirectAgent-191:null) Not retrying security group rules for vm 10 on > failure since host 1 cannot do bridge firewalling > 2014-03-24 08:04:51,286 DEBUG [network.security.SecurityGroupListener] > (DirectAgent-191:null) Failed to program rule > com.cloud.agent.api.SecurityGroupRuleAnswer into host 1 due to Host > 192.168.40.245 cannot do bridge firewalling and updated jobs > 2014-03-24 08:04:51,286 DEBUG [network.security.SecurityGroupListener] > (DirectAgent-191:null) Not retrying security group rules for vm 10 on > failure since host 1 cannot do bridge firewalling > 2014-03-24 08:04:51,287 DEBUG [agent.manager.AgentAttache] > (DirectAgent-191:null) Seq 1-212812149: No more commands found > 2014-03-24 08:04:51,436 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-13:null) SeqA 2-54056: Processing Seq 2-54056: { Cmd > , MgmtId: -1, via: 2, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2014-03-24 08:04:51,450 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-13:null) SeqA 2-54056: Sending Seq 2-54056: { Ans: , > MgmtId: 7063056740127, via: 2, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2014-03-24 08:04:52,799 DEBUG [cloud.api.ApiServlet] > (catalina-exec-10:null) ===START=== 10.29.128.147 -- GET > command=queryAsyncJobResult&jobId=0290d97b-4bd9-4509-8bd2-53b16b032f1b&response=json&sessionkey=bNFqqGTaBxPjbmygj7Q60bFZHOs%3D&_=1395641085710 > 2014-03-24 08:04:52,847 DEBUG [cloud.async.AsyncJobManagerImpl] > (catalina-exec-10:null) Async job-33 = [ > 0290d97b-4bd9-4509-8bd2-53b16b032f1b ] completed > 2014-03-24 08:04:52,881 DEBUG [cloud.api.ApiServlet] > (catalina-exec-10:null) ===END=== 10.29.128.147 -- GET > command=queryAsyncJobResult&jobId=0290d97b-4bd9-4509-8bd2-53b16b032f1b&response=json&sessionkey=bNFqqGTaBxPjbmygj7Q60bFZHOs%3D&_=1395641085710 > 2014-03-24 08:04:56,435 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-15:null) SeqA 2-54057: Processing Seq 2-54057: { Cmd > , MgmtId: -1, via: 2, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2014-03-24 08:04:56,450 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-15:null) SeqA 2-54057: Sending Seq 2-54057: { Ans: , > MgmtId: 7063056740127, via: 2, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2014-03-24 08:04:59,805 DEBUG [cloud.server.StatsCollector] > (StatsCollector-2:null) StorageCollector is running... > 2014-03-24 08:04:59,944 DEBUG [agent.transport.Request] > (StatsCollector-2:null) Seq 3-143857194: Received: { Ans: , MgmtId: > 7063056740127, via: 3, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } > 2014-03-24 08:04:59,962 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-372:null) Seq 1-212812150: Executing request > 2014-03-24 08:05:00,992 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-372:null) Seq 1-212812150: Response Received: > 2014-03-24 08:05:00,994 DEBUG [agent.transport.Request] > (StatsCollector-2:null) Seq 1-212812150: Received: { Ans: , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } > 2014-03-24 08:05:01,477 DEBUG > [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 > is ready to launch secondary storage VM > 2014-03-24 08:05:02,101 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] > (consoleproxy-1:null) Zone 1 is ready to launch console proxy > 2014-03-24 08:05:03,862 DEBUG [cloud.server.StatsCollector] > (StatsCollector-1:null) VmStatsCollector is running... > 2014-03-24 08:05:03,914 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-470:null) Seq 1-212812151: Executing request > 2014-03-24 08:05:04,451 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-470:null) Vm cpu utilization 0.01 > 2014-03-24 08:05:04,451 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-470:null) Vm cpu utilization 0.0 > 2014-03-24 08:05:04,634 DEBUG > [network.router.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:null) Found 0 routers to update status. > 2014-03-24 08:05:04,639 DEBUG > [network.router.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. > 2014-03-24 08:05:04,736 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-470:null) Seq 1-212812151: Response Received: > 2014-03-24 08:05:04,736 DEBUG [agent.transport.Request] > (StatsCollector-1:null) Seq 1-212812151: Received: { Ans: , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 10, { GetVmStatsAnswer } } > 2014-03-24 08:05:06,438 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-10:null) SeqA 2-54058: Processing Seq 2-54058: { Cmd > , MgmtId: -1, via: 2, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2014-03-24 08:05:06,453 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-10:null) SeqA 2-54058: Sending Seq 2-54058: { Ans: , > MgmtId: 7063056740127, via: 2, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2014-03-24 08:05:11,437 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-14:null) SeqA 2-54059: Processing Seq 2-54059: { Cmd > , MgmtId: -1, via: 2, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2014-03-24 08:05:11,450 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-14:null) SeqA 2-54059: Sending Seq 2-54059: { Ans: , > MgmtId: 7063056740127, via: 2, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2014-03-24 08:05:15,829 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-2:null) Ping from 2 > 2014-03-24 08:05:16,438 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-8:null) SeqA 2-54061: Processing Seq 2-54061: { Cmd > , MgmtId: -1, via: 2, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2014-03-24 08:05:16,450 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-8:null) SeqA 2-54061: Sending Seq 2-54061: { Ans: , > MgmtId: 7063056740127, via: 2, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2014-03-24 08:05:16,753 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-6:null) Ping from 3 > 2014-03-24 08:05:16,781 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-372:null) Ping from 1 > 2014-03-24 08:05:19,529 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-470:null) Seq 1-212795397: Executing request > 2014-03-24 08:05:20,130 WARN [xen.resource.CitrixResourceBase] > (DirectAgent-470:null) The VM is now missing marking it as Stopped i-3-10-VM > 2014-03-24 08:05:20,131 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-470:null) Seq 1-212795397: Response Received: > 2014-03-24 08:05:20,133 DEBUG [agent.transport.Request] > (DirectAgent-470:null) Seq 1-212795397: Processing: { Ans: , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.ClusterSyncAnswer":{"_clusterId":1,"_newStates":{"i-3-10-VM":{"t":"927ca03c-7756-4d71-8151-ca26e188a14c","u":"Stopped"}},"_isExecuted":false,"result":true,"wait":0}}] > } > 2014-03-24 08:05:20,148 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (DirectAgent-470:null) VM i-3-10-VM: cs state = Running and realState = > Stopped > 2014-03-24 08:05:20,149 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (DirectAgent-470:null) VM i-3-10-VM: cs state = Running and realState = > Stopped > 2014-03-24 08:05:20,149 DEBUG [cloud.ha.HighAvailabilityManagerImpl] > (DirectAgent-470:null) VM does not require investigation so I'm marking it > as Stopped: VM[User|e461c77d-9d39-43f2-94c3-79d00c36315c] > 2014-03-24 08:05:20,149 WARN [apache.cloudstack.alerts] > (DirectAgent-470:null) alertType:: 8 // dataCenterId:: 1 // podId:: 1 // > clusterId:: null // message:: VM (name: > e461c77d-9d39-43f2-94c3-79d00c36315c, id: 10) stopped unexpectedly on host > id:1, availability zone id:1, pod id:1 > 2014-03-24 08:05:20,180 DEBUG [cloud.ha.HighAvailabilityManagerImpl] > (DirectAgent-470:null) VM is not HA enabled so we're done. > 2014-03-24 08:05:20,200 DEBUG [cloud.capacity.CapacityManagerImpl] > (DirectAgent-470:null) VM state transitted from :Running to Stopping with > event: StopRequestedvm's original host id: 1 new host id: 1 host id before > state transition: 1 > 2014-03-24 08:05:20,213 DEBUG [agent.transport.Request] > (DirectAgent-470:null) Seq 1-212812152: Sending { Cmd , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 100111, > [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-3-10-VM","wait":0}}] > } > 2014-03-24 08:05:20,214 DEBUG [agent.transport.Request] > (DirectAgent-470:null) Seq 1-212812152: Executing: { Cmd , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 100111, > [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-3-10-VM","wait":0}}] > } > 2014-03-24 08:05:20,215 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-209:null) Seq 1-212812152: Executing request > 2014-03-24 08:05:20,423 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-209:null) 9. The VM i-3-10-VM is in Stopping state > 2014-03-24 08:05:20,586 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-209:null) 10. The VM i-3-10-VM is in Stopped state > 2014-03-24 08:05:20,587 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-209:null) Seq 1-212812152: Response Received: > 2014-03-24 08:05:20,588 DEBUG [agent.transport.Request] > (DirectAgent-209:null) Seq 1-212812152: Processing: { Ans: , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 110, > [{"com.cloud.agent.api.StopAnswer":{"platform":"viridian:true;acpi:1;apic:true;pae:true;nx:true;timeoffset:0","result":true,"details":"Stop > VM i-3-10-VM Succeed","wait":0}}] } > 2014-03-24 08:05:20,589 DEBUG [agent.transport.Request] > (DirectAgent-470:null) Seq 1-212812152: Received: { Ans: , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 110, { StopAnswer } } > 2014-03-24 08:05:20,594 DEBUG [agent.manager.AgentAttache] > (DirectAgent-209:null) Seq 1-212812152: No more commands found > 2014-03-24 08:05:20,632 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (DirectAgent-470:null) VM[User|e461c77d-9d39-43f2-94c3-79d00c36315c] is > stopped on the host. Proceeding to release resource held. > 2014-03-24 08:05:20,663 DEBUG [cloud.network.NetworkManagerImpl] > (DirectAgent-470:null) Changing active number of nics for network id=204 on > -1 > 2014-03-24 08:05:20,689 DEBUG [cloud.network.NetworkManagerImpl] > (DirectAgent-470:null) Asking VirtualRouter to release > Nic[17-10-e79b6036-20a0-4a9d-a76e-73010097026a-192.168.40.185] > 2014-03-24 08:05:20,700 DEBUG [cloud.network.NetworkManagerImpl] > (DirectAgent-470:null) Asking SecurityGroupProvider to release > Nic[17-10-e79b6036-20a0-4a9d-a76e-73010097026a-192.168.40.185] > 2014-03-24 08:05:20,701 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (DirectAgent-470:null) Successfully released network resources for the vm > VM[User|e461c77d-9d39-43f2-94c3-79d00c36315c] > 2014-03-24 08:05:20,701 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (DirectAgent-470:null) Successfully released storage resources for the vm > VM[User|e461c77d-9d39-43f2-94c3-79d00c36315c] > 2014-03-24 08:05:20,874 DEBUG [cloud.capacity.CapacityManagerImpl] > (DirectAgent-470:null) VM state transitted from :Stopping to Stopped with > event: OperationSucceededvm's original host id: 1 new host id: null host id > before state transition: 1 > 2014-03-24 08:05:20,900 DEBUG [cloud.capacity.CapacityManagerImpl] > (DirectAgent-470:null) Hosts's actual total CPU: 160000 and CPU after > applying overprovisioning: 160000 > 2014-03-24 08:05:20,901 DEBUG [cloud.capacity.CapacityManagerImpl] > (DirectAgent-470:null) Hosts's actual total RAM: 540213924096 and RAM after > applying overprovisioning: 540213936128 > 2014-03-24 08:05:20,901 DEBUG [cloud.capacity.CapacityManagerImpl] > (DirectAgent-470:null) release cpu from host: 1, old used: 4500,reserved: > 0, actual total: 160000, total with overprovisioning: 160000; new used: > 3000,reserved:1500; movedfromreserved: false,moveToReserveredtrue > 2014-03-24 08:05:20,901 DEBUG [cloud.capacity.CapacityManagerImpl] > (DirectAgent-470:null) release mem from host: 1, old used: > 3623878656,reserved: 0, total: 540213936128; new used: > 2550136832,reserved:1073741824; movedfromreserved: > false,moveToReserveredtrue > 2014-03-24 08:05:20,962 INFO [cloud.ha.HighAvailabilityManagerImpl] > (DirectAgent-470:null) Schedule vm for HA: > VM[User|e461c77d-9d39-43f2-94c3-79d00c36315c] > 2014-03-24 08:05:20,982 INFO [cloud.ha.HighAvailabilityManagerImpl] > (HA-Worker-0:work-13) Processing HAWork[13-HA-10-Stopped-Scheduled] > 2014-03-24 08:05:21,003 INFO [cloud.ha.HighAvailabilityManagerImpl] > (HA-Worker-0:work-13) HA on VM[User|e461c77d-9d39-43f2-94c3-79d00c36315c] > 2014-03-24 08:05:21,019 DEBUG [cloud.ha.HighAvailabilityManagerImpl] > (HA-Worker-0:work-13) VM is not HA enabled so we're done. > 2014-03-24 08:05:21,019 INFO [cloud.ha.HighAvailabilityManagerImpl] > (HA-Worker-0:work-13) Completed HAWork[13-HA-10-Stopped-Scheduled] > 2014-03-24 08:05:21,023 DEBUG [agent.transport.Request] > (DirectAgent-470:null) Seq 1-212812153: Sending { Cmd , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 100111, > [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-3-10-VM","wait":0}}] > } > 2014-03-24 08:05:21,024 DEBUG [agent.transport.Request] > (DirectAgent-470:null) Seq 1-212812153: Executing: { Cmd , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 100111, > [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-3-10-VM","wait":0}}] > } > 2014-03-24 08:05:21,024 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-133:null) Seq 1-212812153: Executing request > 2014-03-24 08:05:21,383 INFO [xen.resource.CitrixResourceBase] > (DirectAgent-133:null) VM does not exist on > XenServer927ca03c-7756-4d71-8151-ca26e188a14c > 2014-03-24 08:05:21,384 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-133:null) Seq 1-212812153: Response Received: > 2014-03-24 08:05:21,385 DEBUG [agent.transport.Request] > (DirectAgent-133:null) Seq 1-212812153: Processing: { Ans: , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 110, > [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not > exist","wait":0}}] } > 2014-03-24 08:05:21,386 DEBUG [agent.transport.Request] > (DirectAgent-470:null) Seq 1-212812153: Received: { Ans: , MgmtId: > 7063056740127, via: 1, Ver: v1, Flags: 110, { StopAnswer } } > 2014-03-24 08:05:21,387 DEBUG [agent.manager.AgentAttache] > (DirectAgent-133:null) Seq 1-212812153: No more commands found > ^C > > >
