cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Dean Kamali <dean.kam...@gmail.com>
Subject Re: VHD-util
Date Fri, 04 Oct 2013 06:10:29 GMT
Just to give you guys an update make sure you download vhd-util from
http://download.cloud.com.s3.amazonaws.com/tools/vhd-util to
/opt/xensource/bin on each xenserver and make it executable by running
chmod o+x vhd-util

Best


On Tue, Jul 16, 2013 at 12:09 PM, Bradley Hieber <mercsniper@gmail.com>wrote:

> I SFTP'd it to /opt/xensource/bin. Running Management server now. I will
> update on progress.
>
>
> On Tue, Jul 16, 2013 at 1:05 AM, Sanjay Tripathi <
> sanjay.tripathi@citrix.com
> > wrote:
>
> > For CS, vhd-util should present in /opt/xensource/bin  location. If it is
> > not there, can you copy it to this location and see if this helps.
> >
> > > -----Original Message-----
> > > From: Bradley Hieber [mailto:mercsniper@gmail.com]
> > > Sent: Tuesday, July 16, 2013 3:15 AM
> > > To: users@cloudstack.apache.org
> > > Subject: Re: VHD-util
> > >
> > > http://pastebin.com/Nu8Cfpfq
> > >
> > >
> > > On Mon, Jul 15, 2013 at 5:43 PM, Dean Kamali <dean.kamali@gmail.com>
> > > wrote:
> > >
> > > > Lol please use past bin for your logs
> > > > On Jul 15, 2013 5:41 PM, "Bradley Hieber" <mercsniper@gmail.com>
> > wrote:
> > > >
> > > > > 2013-07-15 12:09:11,279 DEBUG
> > > > > [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
> > > Zone
> > > > 1
> > > > > is ready to launch secondary storage VM
> > > > > 2013-07-15 12:09:11,286 INFO
> > > > >  [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
> > > > (secstorage-1:null)
> > > > > No running secondary storage vms found in datacenter id=1, starting
> > one
> > > > > 2013-07-15 12:09:11,298 INFO
> > > > >  [storage.secondary.SecondaryStorageManagerImpl]
> (secstorage-1:null)
> > > > Found
> > > > > a stopped secondary storage vm, bring it up to running pool.
> > > secStorageVm
> > > > > vm id : 383
> > > > > 2013-07-15 12:09:11,305 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) 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
> > > > > 2013-07-15 12:09:11,305 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) Successfully transitioned to start state for
> > > > > VM[SecondaryStorageVm|s-383-VM] reservation id =
> > > > > 6481cf60-9be7-403d-a53c-b514af71184d
> > > > > 2013-07-15 12:09:11,310 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) Trying to deploy VM, vm has dcId: 1 and podId:
> 1
> > > > > 2013-07-15 12:09:11,310 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) Deploy avoids pods: null, clusters: null,
> hosts:
> > null
> > > > > 2013-07-15 12:09:11,312 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) DeploymentPlanner allocation algorithm: random
> > > > > 2013-07-15 12:09:11,313 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Trying to allocate a host and storage pools
> from
> > > > dc:1,
> > > > > pod:1,cluster:null, requested cpu: 500, requested ram: 268435456
> > > > > 2013-07-15 12:09:11,313 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Is ROOT volume READY (pool already allocated)?:
> > No
> > > > > 2013-07-15 12:09:11,313 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Searching resources only under specified Pod: 1
> > > > > 2013-07-15 12:09:11,314 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Listing clusters in order of aggregate
> capacity,
> > that
> > > > > have (atleast one host with) enough CPU and RAM capacity under this
> > > Pod:
> > > > 1
> > > > > 2013-07-15 12:09:11,316 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) CPUOverprovisioningFactor considered: 1.0
> > > > > 2013-07-15 12:09:11,323 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Checking resources in Cluster: 3 under Pod: 1
> > > > > 2013-07-15 12:09:11,323 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1
> >  pod:1
> > > > >  cluster:3
> > > > > 2013-07-15 12:09:11,325 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1
> > hosts to
> > > > > check for allocation: [Host[-7-Routing]]
> > > > > 2013-07-15 12:09:11,328 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for
> allocation
> > > > after
> > > > > prioritization: [Host[-7-Routing]]
> > > > > 2013-07-15 12:09:11,329 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz,
> > > Ram=256
> > > > > 2013-07-15 12:09:11,331 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Checking if host: 7 has
> > enough
> > > > > capacity for requested CPU: 500 and requested RAM: 268435456 ,
> > > > > cpuOverprovisioningFactor: 1.0
> > > > > 2013-07-15 12:09:11,334 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Hosts's actual total CPU:
> > 25608
> > > > and
> > > > > CPU after applying overprovisioning: 25608
> > > > > 2013-07-15 12:09:11,334 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Free CPU: 25608 , Requested
> > CPU:
> > > > > 500
> > > > > 2013-07-15 12:09:11,335 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Free RAM: 16199733312 ,
> > > Requested
> > > > > RAM: 268435456
> > > > > 2013-07-15 12:09:11,335 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Host has enough CPU and RAM
> > > > > available
> > > > > 2013-07-15 12:09:11,335 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from
> > host:
> > > > 7,
> > > > > used: 0, reserved: 0, actual total: 25608, total with
> > overprovisioning:
> > > > > 25608; requested cpu:500,alloc_from_last_host?:false
> > > > > ,considerReservedCapacity?: true
> > > > > 2013-07-15 12:09:11,336 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from
> > host:
> > > > 7,
> > > > > used: 0, reserved: 0, total: 16199733312; requested mem:
> > > > > 268435456,alloc_from_last_host?:false ,considerReservedCapacity?:
> > true
> > > > > 2013-07-15 12:09:11,336 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Found a suitable host,
> > adding to
> > > > > list: 7
> > > > > 2013-07-15 12:09:11,336 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 1
> > > > suitable
> > > > > hosts
> > > > > 2013-07-15 12:09:11,338 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Checking suitable pools for volume (Id, Type):
> > > > > (383,ROOT)
> > > > > 2013-07-15 12:09:11,338 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) We need to allocate new storagepool for this
> > volume
> > > > > 2013-07-15 12:09:11,339 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Calling StoragePoolAllocators to find suitable
> > pools
> > > > > 2013-07-15 12:09:11,340 DEBUG
> > > > > [storage.allocator.FirstFitStoragePoolAllocator]
> (secstorage-1:null)
> > > > > Looking for pools in dc: 1  pod:1  cluster:3
> > > > > 2013-07-15 12:09:11,341 DEBUG
> > > > > [storage.allocator.FirstFitStoragePoolAllocator]
> (secstorage-1:null)
> > > > > FirstFitStoragePoolAllocator has 1 pools to check for allocation
> > > > > 2013-07-15 12:09:11,342 DEBUG
> > > > > [storage.allocator.AbstractStoragePoolAllocator]
> (secstorage-1:null)
> > > > > Checking if storage pool is suitable, name: Primary ,poolId: 204
> > > > > 2013-07-15 12:09:11,342 DEBUG
> > > > > [storage.allocator.AbstractStoragePoolAllocator]
> (secstorage-1:null)
> > Is
> > > > > localStorageAllocationNeeded? false
> > > > > 2013-07-15 12:09:11,342 DEBUG
> > > > > [storage.allocator.AbstractStoragePoolAllocator]
> (secstorage-1:null)
> > Is
> > > > > storage pool shared? true
> > > > > 2013-07-15 12:09:11,344 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (secstorage-1:null) Checking pool 204 for storage, totalSize:
> > > > 528446128128,
> > > > > usedBytes: 207355904, usedPct: 3.9238797100198326E-4, disable
> > > threshold:
> > > > > 0.85
> > > > > 2013-07-15 12:09:11,350 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (secstorage-1:null) Checking pool: 204 for volume allocation
> > > > > [Vol[383|vm=383|ROOT]], maxSize : 1056892256256,
> totalAllocatedSize :
> > > 0,
> > > > > askingSize : 0, allocated disable threshold: 0.85
> > > > > 2013-07-15 12:09:11,350 DEBUG
> > > > > [storage.allocator.FirstFitStoragePoolAllocator]
> (secstorage-1:null)
> > > > > FirstFitStoragePoolAllocator returning 1 suitable storage pools
> > > > > 2013-07-15 12:09:11,350 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Trying to find a potenial host and associated
> > storage
> > > > > pools from the suitable host/pool lists for this VM
> > > > > 2013-07-15 12:09:11,351 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Checking if host: 7 can access any suitable
> > storage
> > > > > pool for volume: ROOT
> > > > > 2013-07-15 12:09:11,352 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Host: 7 can access pool: 204
> > > > > 2013-07-15 12:09:11,352 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Found a potential host id: 7 name: xenserver-01
> > and
> > > > > associated storage pools for this VM
> > > > > 2013-07-15 12:09:11,354 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Returning Deployment Destination:
> > > > >
> > > > >
> > > > Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type--
> > > >Pool(Id))]
> > > > > :
> > > > >
> > > > >
> > > > Dest[Zone(1)-Pod(1)-Cluster(3)-Host(7)-Storage(Volume(383|ROOT--
> > > >Pool(204))]
> > > > > 2013-07-15 12:09:11,354 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) Deployment found  -
> > > > P0=VM[SecondaryStorageVm|s-383-VM],
> > > > >
> > > > >
> > > >
> P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type--
> > > >Pool(Id))]
> > > > > :
> > > > >
> > > > >
> > > > Dest[Zone(1)-Pod(1)-Cluster(3)-Host(7)-Storage(Volume(383|ROOT--
> > > >Pool(204))]
> > > > > 2013-07-15 12:09:11,360 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) VM state transitted from :Starting to Starting
> > with
> > > > > event: OperationRetryvm's original host id: null new host id: 7
> host
> > id
> > > > > before state transition: null
> > > > > 2013-07-15 12:09:11,367 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) Hosts's actual total CPU: 25608 and CPU after
> > > > applying
> > > > > overprovisioning: 25608
> > > > > 2013-07-15 12:09:11,367 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) We are allocating VM, increasing the used
> > capacity of
> > > > > this host:7
> > > > > 2013-07-15 12:09:11,367 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) Current Used CPU: 0 , Free CPU:25608 ,Requested
> > > CPU:
> > > > > 500
> > > > > 2013-07-15 12:09:11,368 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) Current Used RAM: 0 , Free RAM:16199733312
> > > ,Requested
> > > > > RAM: 268435456
> > > > > 2013-07-15 12:09:11,368 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) CPU STATS after allocation: for host: 7, old
> > used: 0,
> > > > > old reserved: 0, actual total: 25608, total with overprovisioning:
> > 25608;
> > > > > new used:500, reserved:0; requested cpu:500,alloc_from_last:false
> > > > > 2013-07-15 12:09:11,369 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) RAM STATS after allocation: for host: 7, old
> > used: 0,
> > > > > old reserved: 0, total: 16199733312; new used: 268435456, reserved:
> > 0;
> > > > > requested mem: 268435456,alloc_from_last:false
> > > > > 2013-07-15 12:09:11,371 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) VM is being created in podId: 1
> > > > > 2013-07-15 12:09:11,376 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Lock is acquired for network id 204 as a part
> of
> > > > > network implement
> > > > > 2013-07-15 12:09:11,376 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Network id=204 is already implemented
> > > > > 2013-07-15 12:09:11,377 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Lock is released for network id 204 as a part
> of
> > > > > network implement
> > > > > 2013-07-15 12:09:11,399 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking NiciraNvp to prepare for
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:11,399 DEBUG [network.element.NiciraNvpElement]
> > > > > (secstorage-1:null) Checking if NiciraNvpElement can handle service
> > > > > Connectivity on network defaultGuestNetwork
> > > > > 2013-07-15 12:09:11,400 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking JuniperSRX to prepare for
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:11,400 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Netscaler to prepare for
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:11,401 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking F5BigIP to prepare for
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:11,401 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:11,401 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking BigSwitchVnsElement to prepare for
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:11,401 DEBUG [network.element.BigSwitchVnsElement]
> > > > > (secstorage-1:null) Checking if BigSwitchVnsElement can handle
> > service
> > > > > Connectivity on network defaultGuestNetwork
> > > > > 2013-07-15 12:09:11,402 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VirtualRouter to prepare for
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:11,402 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Ovs to prepare for
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:11,402 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking SecurityGroupProvider to prepare for
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:11,402 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VpcVirtualRouter to prepare for
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:11,402 WARN
> > > [network.element.VpcVirtualRouterElement]
> > > > > (secstorage-1:null) Network Ntwk[204|Guest|6] is not associated
> with
> > > any
> > > > > VPC
> > > > > 2013-07-15 12:09:11,415 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Lock is acquired for network id 202 as a part
> of
> > > > > network implement
> > > > > 2013-07-15 12:09:11,416 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Network id=202 is already implemented
> > > > > 2013-07-15 12:09:11,416 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Lock is released for network id 202 as a part
> of
> > > > > network implement
> > > > > 2013-07-15 12:09:11,433 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking NiciraNvp to prepare for
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-169.254.3.135]
> > > > > 2013-07-15 12:09:11,434 DEBUG [network.element.NiciraNvpElement]
> > > > > (secstorage-1:null) Checking if NiciraNvpElement can handle service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:11,434 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking JuniperSRX to prepare for
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-169.254.3.135]
> > > > > 2013-07-15 12:09:11,434 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Netscaler to prepare for
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-169.254.3.135]
> > > > > 2013-07-15 12:09:11,435 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking F5BigIP to prepare for
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-169.254.3.135]
> > > > > 2013-07-15 12:09:11,435 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-169.254.3.135]
> > > > > 2013-07-15 12:09:11,436 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking BigSwitchVnsElement to prepare for
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-169.254.3.135]
> > > > > 2013-07-15 12:09:11,436 DEBUG [network.element.BigSwitchVnsElement]
> > > > > (secstorage-1:null) Checking if BigSwitchVnsElement can handle
> > service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:11,436 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VirtualRouter to prepare for
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-169.254.3.135]
> > > > > 2013-07-15 12:09:11,436 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Ovs to prepare for
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-169.254.3.135]
> > > > > 2013-07-15 12:09:11,436 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking SecurityGroupProvider to prepare for
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-169.254.3.135]
> > > > > 2013-07-15 12:09:11,436 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VpcVirtualRouter to prepare for
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-169.254.3.135]
> > > > > 2013-07-15 12:09:11,436 WARN
> > > [network.element.VpcVirtualRouterElement]
> > > > > (secstorage-1:null) Network Ntwk[202|Control|3] is not associated
> > with
> > > > any
> > > > > VPC
> > > > > 2013-07-15 12:09:11,439 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Lock is acquired for network id 201 as a part
> of
> > > > > network implement
> > > > > 2013-07-15 12:09:11,439 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Network id=201 is already implemented
> > > > > 2013-07-15 12:09:11,440 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Lock is released for network id 201 as a part
> of
> > > > > network implement
> > > > > 2013-07-15 12:09:11,455 DEBUG [network.guru.PodBasedNetworkGuru]
> > > > > (secstorage-1:null) Allocated a nic
> > > > >
> > > >
> NicProfile[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.198-
> > > null
> > > > > for VM[SecondaryStorageVm|s-383-VM]
> > > > > 2013-07-15 12:09:11,458 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking NiciraNvp to prepare for
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.198]
> > > > > 2013-07-15 12:09:11,458 DEBUG [network.element.NiciraNvpElement]
> > > > > (secstorage-1:null) Checking if NiciraNvpElement can handle service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:11,458 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking JuniperSRX to prepare for
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.198]
> > > > > 2013-07-15 12:09:11,459 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Netscaler to prepare for
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.198]
> > > > > 2013-07-15 12:09:11,459 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking F5BigIP to prepare for
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.198]
> > > > > 2013-07-15 12:09:11,459 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.198]
> > > > > 2013-07-15 12:09:11,460 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking BigSwitchVnsElement to prepare for
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.198]
> > > > > 2013-07-15 12:09:11,460 DEBUG [network.element.BigSwitchVnsElement]
> > > > > (secstorage-1:null) Checking if BigSwitchVnsElement can handle
> > service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:11,460 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VirtualRouter to prepare for
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.198]
> > > > > 2013-07-15 12:09:11,460 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Ovs to prepare for
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.198]
> > > > > 2013-07-15 12:09:11,460 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking SecurityGroupProvider to prepare for
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.198]
> > > > > 2013-07-15 12:09:11,460 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VpcVirtualRouter to prepare for
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.198]
> > > > > 2013-07-15 12:09:11,461 WARN
> > > [network.element.VpcVirtualRouterElement]
> > > > > (secstorage-1:null) Network Ntwk[201|Management|2] is not
> associated
> > > with
> > > > > any VPC
> > > > > 2013-07-15 12:09:11,463 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Lock is acquired for network id 203 as a part
> of
> > > > > network implement
> > > > > 2013-07-15 12:09:11,464 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Network id=203 is already implemented
> > > > > 2013-07-15 12:09:11,465 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Lock is released for network id 203 as a part
> of
> > > > > network implement
> > > > > 2013-07-15 12:09:11,486 DEBUG [network.guru.StorageNetworkGuru]
> > > > > (secstorage-1:null) Allocated a storage nic
> > > > >
> > > >
> NicProfile[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.57-
> > > null
> > > > > for VM[SecondaryStorageVm|s-383-VM]
> > > > > 2013-07-15 12:09:11,489 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking NiciraNvp to prepare for
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.57]
> > > > > 2013-07-15 12:09:11,489 DEBUG [network.element.NiciraNvpElement]
> > > > > (secstorage-1:null) Checking if NiciraNvpElement can handle service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:11,490 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking JuniperSRX to prepare for
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.57]
> > > > > 2013-07-15 12:09:11,490 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Netscaler to prepare for
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.57]
> > > > > 2013-07-15 12:09:11,490 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking F5BigIP to prepare for
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.57]
> > > > > 2013-07-15 12:09:11,491 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.57]
> > > > > 2013-07-15 12:09:11,491 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking BigSwitchVnsElement to prepare for
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.57]
> > > > > 2013-07-15 12:09:11,491 DEBUG [network.element.BigSwitchVnsElement]
> > > > > (secstorage-1:null) Checking if BigSwitchVnsElement can handle
> > service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:11,492 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VirtualRouter to prepare for
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.57]
> > > > > 2013-07-15 12:09:11,492 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Ovs to prepare for
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.57]
> > > > > 2013-07-15 12:09:11,492 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking SecurityGroupProvider to prepare for
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.57]
> > > > > 2013-07-15 12:09:11,492 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VpcVirtualRouter to prepare for
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.57]
> > > > > 2013-07-15 12:09:11,492 WARN
> > > [network.element.VpcVirtualRouterElement]
> > > > > (secstorage-1:null) Network Ntwk[203|Storage|4] is not associated
> > with
> > > > any
> > > > > VPC
> > > > > 2013-07-15 12:09:11,495 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (secstorage-1:null) Checking if we need to prepare 1 volumes for
> > > > > VM[SecondaryStorageVm|s-383-VM]
> > > > > 2013-07-15 12:09:11,500 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (secstorage-1:null) Creating volume: Vol[383|vm=383|ROOT]
> > > > > 2013-07-15 12:09:11,500 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (secstorage-1:null) Trying to create in Pool[204|NetworkFilesystem]
> > > > > 2013-07-15 12:09:11,517 DEBUG [cloud.template.TemplateManagerImpl]
> > > > > (secstorage-1:null) Downloading 1 via 7
> > > > > 2013-07-15 12:09:11,525 DEBUG [agent.transport.Request]
> > > > (secstorage-1:null)
> > > > > Seq 7-1661993060: Sending  { Cmd , MgmtId: 52231432591, via: 7,
> Ver:
> > v1,
> > > > > Flags: 100111,
> > > > >
> > > > >
> > > >
> > > [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/483c879b
> > > -67a3-3830-9c87-1997efb60ed0","poolUuid":"483c879b-67a3-3830-9c87-
> > >
> 1997efb60ed0","poolId":204,"primaryPool":{"id":204,"uuid":"483c879b-67a3-
> > > 3830-9c87-
> > >
> 1997efb60ed0","host":"192.168.2.123","path":"/export/primary","port":2049
> > > ,"type":"NetworkFilesystem"},"secondaryStorageUrl":"nfs://
> > > > > 192.168.2.123/export/secondary","primaryStorageUrl":"nfs://
> > > > > 192.168.2.123/export/primary","url":"nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/
> > > > > ","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
> > > > > }
> > > > > 2013-07-15 12:09:11,527 DEBUG [agent.transport.Request]
> > > > (secstorage-1:null)
> > > > > Seq 7-1661993060: Executing:  { Cmd , MgmtId: 52231432591, via: 7,
> > Ver:
> > > > v1,
> > > > > Flags: 100111,
> > > > >
> > > > >
> > > >
> > > [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/483c879b
> > > -67a3-3830-9c87-1997efb60ed0","poolUuid":"483c879b-67a3-3830-9c87-
> > >
> 1997efb60ed0","poolId":204,"primaryPool":{"id":204,"uuid":"483c879b-67a3-
> > > 3830-9c87-
> > >
> 1997efb60ed0","host":"192.168.2.123","path":"/export/primary","port":2049
> > > ,"type":"NetworkFilesystem"},"secondaryStorageUrl":"nfs://
> > > > > 192.168.2.123/export/secondary","primaryStorageUrl":"nfs://
> > > > > 192.168.2.123/export/primary","url":"nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/
> > > > > ","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
> > > > > }
> > > > > 2013-07-15 12:09:11,528 DEBUG [agent.manager.DirectAgentAttache]
> > > > > (DirectAgent-60:null) Seq 7-1661993060: Executing request
> > > > > 2013-07-15 12:09:12,427 DEBUG
> > > > [cloud.consoleproxy.ConsoleProxyManagerImpl]
> > > > > (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> > > > > 2013-07-15 12:09:12,428 DEBUG
> > > > [cloud.consoleproxy.ConsoleProxyManagerImpl]
> > > > > (consoleproxy-1:null) Expand console proxy standby capacity for
> zone
> > > Blue
> > > > > 2013-07-15 12:09:12,430 INFO
> > > >  [cloud.consoleproxy.ConsoleProxyManagerImpl]
> > > > > (consoleproxy-1:null) Found a stopped console proxy, bring it up to
> > > > running
> > > > > pool. proxy vm id : 378
> > > > > 2013-07-15 12:09:12,437 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:null) 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
> > > > > 2013-07-15 12:09:12,437 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (consoleproxy-1:null) Successfully transitioned to start state for
> > > > > VM[ConsoleProxy|v-378-VM] reservation id =
> > > > > db45f1f8-1681-46bd-b31a-22b10ee369dd
> > > > > 2013-07-15 12:09:12,441 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (consoleproxy-1:null) Trying to deploy VM, vm has dcId: 1 and
> podId:
> > 1
> > > > > 2013-07-15 12:09:12,441 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (consoleproxy-1:null) Deploy avoids pods: null, clusters: null,
> > hosts:
> > > > null
> > > > > 2013-07-15 12:09:12,443 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) DeploymentPlanner allocation algorithm:
> random
> > > > > 2013-07-15 12:09:12,443 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Trying to allocate a host and storage pools
> > from
> > > > > dc:1, pod:1,cluster:null, requested cpu: 500, requested ram:
> > 1073741824
> > > > > 2013-07-15 12:09:12,444 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Is ROOT volume READY (pool already
> allocated)?:
> > > No
> > > > > 2013-07-15 12:09:12,444 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Searching resources only under specified
> Pod: 1
> > > > > 2013-07-15 12:09:12,445 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Listing clusters in order of aggregate
> > capacity,
> > > > that
> > > > > have (atleast one host with) enough CPU and RAM capacity under this
> > > Pod:
> > > > 1
> > > > > 2013-07-15 12:09:12,446 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) CPUOverprovisioningFactor considered: 1.0
> > > > > 2013-07-15 12:09:12,453 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Checking resources in Cluster: 3 under Pod: 1
> > > > > 2013-07-15 12:09:12,453 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc:
> 1
> > > >  pod:1
> > > > >  cluster:3
> > > > > 2013-07-15 12:09:12,455 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1
> > hosts
> > > > to
> > > > > check for allocation: [Host[-7-Routing]]
> > > > > 2013-07-15 12:09:12,457 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for
> > allocation
> > > > > after prioritization: [Host[-7-Routing]]
> > > > > 2013-07-15 12:09:12,458 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz,
> > > > > Ram=1024
> > > > > 2013-07-15 12:09:12,460 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 7 has
> > enough
> > > > > capacity for requested CPU: 500 and requested RAM: 1073741824 ,
> > > > > cpuOverprovisioningFactor: 1.0
> > > > > 2013-07-15 12:09:12,462 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CPU:
> > 25608
> > > > > and CPU after applying overprovisioning: 25608
> > > > > 2013-07-15 12:09:12,462 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 25108 ,
> Requested
> > > > CPU:
> > > > > 500
> > > > > 2013-07-15 12:09:12,463 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 15931297856 ,
> > > > Requested
> > > > > RAM: 1073741824
> > > > > 2013-07-15 12:09:12,463 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and
> RAM
> > > > > available
> > > > > 2013-07-15 12:09:12,463 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from
> > host:
> > > > > 7, used: 500, reserved: 0, actual total: 25608, total with
> > > > > overprovisioning: 25608; requested
> > cpu:500,alloc_from_last_host?:false
> > > > > ,considerReservedCapacity?: true
> > > > > 2013-07-15 12:09:12,464 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from
> > > host:
> > > > > 7, used: 268435456, reserved: 0, total: 16199733312; requested mem:
> > > > > 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?:
> > > true
> > > > > 2013-07-15 12:09:12,464 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host,
> > adding
> > > > to
> > > > > list: 7
> > > > > 2013-07-15 12:09:12,464 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning
> 1
> > > > > suitable hosts
> > > > > 2013-07-15 12:09:12,466 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Checking suitable pools for volume (Id,
> Type):
> > > > > (378,ROOT)
> > > > > 2013-07-15 12:09:12,466 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) We need to allocate new storagepool for this
> > > volume
> > > > > 2013-07-15 12:09:12,466 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Calling StoragePoolAllocators to find
> suitable
> > > > pools
> > > > > 2013-07-15 12:09:12,467 DEBUG
> > > > > [storage.allocator.FirstFitStoragePoolAllocator]
> > (consoleproxy-1:null)
> > > > > Looking for pools in dc: 1  pod:1  cluster:3
> > > > > 2013-07-15 12:09:12,468 DEBUG
> > > > > [storage.allocator.FirstFitStoragePoolAllocator]
> > (consoleproxy-1:null)
> > > > > FirstFitStoragePoolAllocator has 1 pools to check for allocation
> > > > > 2013-07-15 12:09:12,469 DEBUG
> > > > > [storage.allocator.AbstractStoragePoolAllocator]
> > (consoleproxy-1:null)
> > > > > Checking if storage pool is suitable, name: Primary ,poolId: 204
> > > > > 2013-07-15 12:09:12,469 DEBUG
> > > > > [storage.allocator.AbstractStoragePoolAllocator]
> > (consoleproxy-1:null) Is
> > > > > localStorageAllocationNeeded? false
> > > > > 2013-07-15 12:09:12,469 DEBUG
> > > > > [storage.allocator.AbstractStoragePoolAllocator]
> > (consoleproxy-1:null) Is
> > > > > storage pool shared? true
> > > > > 2013-07-15 12:09:12,471 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (consoleproxy-1:null) Checking pool 204 for storage, totalSize:
> > > > > 528446128128, usedBytes: 207355904, usedPct: 3.9238797100198326E-4,
> > > > disable
> > > > > threshold: 0.85
> > > > > 2013-07-15 12:09:12,476 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (consoleproxy-1:null) Checking pool: 204 for volume allocation
> > > > > [Vol[378|vm=378|ROOT]], maxSize : 1056892256256,
> totalAllocatedSize :
> > > 0,
> > > > > askingSize : 0, allocated disable threshold: 0.85
> > > > > 2013-07-15 12:09:12,477 DEBUG
> > > > > [storage.allocator.FirstFitStoragePoolAllocator]
> > (consoleproxy-1:null)
> > > > > FirstFitStoragePoolAllocator returning 1 suitable storage pools
> > > > > 2013-07-15 12:09:12,477 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Trying to find a potenial host and associated
> > > > storage
> > > > > pools from the suitable host/pool lists for this VM
> > > > > 2013-07-15 12:09:12,477 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Checking if host: 7 can access any suitable
> > storage
> > > > > pool for volume: ROOT
> > > > > 2013-07-15 12:09:12,479 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Host: 7 can access pool: 204
> > > > > 2013-07-15 12:09:12,479 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Found a potential host id: 7 name:
> xenserver-01
> > > and
> > > > > associated storage pools for this VM
> > > > > 2013-07-15 12:09:12,481 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (consoleproxy-1:null) Returning Deployment Destination:
> > > > >
> > > > >
> > > > Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type--
> > > >Pool(Id))]
> > > > > :
> > > > >
> > > > >
> > > > Dest[Zone(1)-Pod(1)-Cluster(3)-Host(7)-Storage(Volume(378|ROOT--
> > > >Pool(204))]
> > > > > 2013-07-15 12:09:12,481 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (consoleproxy-1:null) Deployment found  - P0=VM[ConsoleProxy|v-378-
> > > VM],
> > > > >
> > > > >
> > > >
> P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type--
> > > >Pool(Id))]
> > > > > :
> > > > >
> > > > >
> > > > Dest[Zone(1)-Pod(1)-Cluster(3)-Host(7)-Storage(Volume(378|ROOT--
> > > >Pool(204))]
> > > > > 2013-07-15 12:09:12,487 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:null) VM state transitted from :Starting to
> Starting
> > with
> > > > > event: OperationRetryvm's original host id: null new host id: 7
> host
> > id
> > > > > before state transition: null
> > > > > 2013-07-15 12:09:12,493 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:null) Hosts's actual total CPU: 25608 and CPU after
> > > > > applying overprovisioning: 25608
> > > > > 2013-07-15 12:09:12,494 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:null) We are allocating VM, increasing the used
> > capacity
> > > > of
> > > > > this host:7
> > > > > 2013-07-15 12:09:12,494 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:null) Current Used CPU: 500 , Free CPU:25108
> > > ,Requested
> > > > > CPU: 500
> > > > > 2013-07-15 12:09:12,494 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:null) Current Used RAM: 268435456 , Free
> > > RAM:15931297856
> > > > > ,Requested RAM: 1073741824
> > > > > 2013-07-15 12:09:12,495 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:null) CPU STATS after allocation: for host: 7, old
> > used:
> > > > > 500, old reserved: 0, actual total: 25608, total with
> > overprovisioning:
> > > > > 25608; new used:1000, reserved:0; requested
> > > cpu:500,alloc_from_last:false
> > > > > 2013-07-15 12:09:12,495 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (consoleproxy-1:null) RAM STATS after allocation: for host: 7, old
> > used:
> > > > > 268435456, old reserved: 0, total: 16199733312; new used:
> 1342177280,
> > > > > reserved: 0; requested mem: 1073741824,alloc_from_last:false
> > > > > 2013-07-15 12:09:12,499 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (consoleproxy-1:null) VM is being created in podId: 1
> > > > > 2013-07-15 12:09:12,503 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Lock is acquired for network id 204 as a part
> > of
> > > > > network implement
> > > > > 2013-07-15 12:09:12,504 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Network id=204 is already implemented
> > > > > 2013-07-15 12:09:12,504 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Lock is released for network id 204 as a part
> > of
> > > > > network implement
> > > > > 2013-07-15 12:09:12,529 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking NiciraNvp to prepare for
> > > > > Nic[1506-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.201]
> > > > > 2013-07-15 12:09:12,530 DEBUG [network.element.NiciraNvpElement]
> > > > > (consoleproxy-1:null) Checking if NiciraNvpElement can handle
> service
> > > > > Connectivity on network defaultGuestNetwork
> > > > > 2013-07-15 12:09:12,530 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking JuniperSRX to prepare for
> > > > > Nic[1506-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.201]
> > > > > 2013-07-15 12:09:12,530 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking Netscaler to prepare for
> > > > > Nic[1506-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.201]
> > > > > 2013-07-15 12:09:12,531 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking F5BigIP to prepare for
> > > > > Nic[1506-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.201]
> > > > > 2013-07-15 12:09:12,531 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking CiscoNexus1000vVSM to prepare for
> > > > > Nic[1506-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.201]
> > > > > 2013-07-15 12:09:12,531 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking BigSwitchVnsElement to prepare for
> > > > > Nic[1506-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.201]
> > > > > 2013-07-15 12:09:12,532 DEBUG [network.element.BigSwitchVnsElement]
> > > > > (consoleproxy-1:null) Checking if BigSwitchVnsElement can handle
> > > service
> > > > > Connectivity on network defaultGuestNetwork
> > > > > 2013-07-15 12:09:12,532 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking VirtualRouter to prepare for
> > > > > Nic[1506-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.201]
> > > > > 2013-07-15 12:09:12,532 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking Ovs to prepare for
> > > > > Nic[1506-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.201]
> > > > > 2013-07-15 12:09:12,532 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking SecurityGroupProvider to prepare for
> > > > > Nic[1506-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.201]
> > > > > 2013-07-15 12:09:12,532 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking VpcVirtualRouter to prepare for
> > > > > Nic[1506-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.201]
> > > > > 2013-07-15 12:09:12,532 WARN
> > > [network.element.VpcVirtualRouterElement]
> > > > > (consoleproxy-1:null) Network Ntwk[204|Guest|6] is not associated
> > with
> > > > any
> > > > > VPC
> > > > > 2013-07-15 12:09:12,538 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Lock is acquired for network id 202 as a part
> > of
> > > > > network implement
> > > > > 2013-07-15 12:09:12,539 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Network id=202 is already implemented
> > > > > 2013-07-15 12:09:12,539 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Lock is released for network id 202 as a part
> > of
> > > > > network implement
> > > > > 2013-07-15 12:09:12,560 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking NiciraNvp to prepare for
> > > > > Nic[1507-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-169.254.2.23]
> > > > > 2013-07-15 12:09:12,560 DEBUG [network.element.NiciraNvpElement]
> > > > > (consoleproxy-1:null) Checking if NiciraNvpElement can handle
> service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:12,560 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking JuniperSRX to prepare for
> > > > > Nic[1507-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-169.254.2.23]
> > > > > 2013-07-15 12:09:12,561 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking Netscaler to prepare for
> > > > > Nic[1507-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-169.254.2.23]
> > > > > 2013-07-15 12:09:12,561 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking F5BigIP to prepare for
> > > > > Nic[1507-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-169.254.2.23]
> > > > > 2013-07-15 12:09:12,562 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking CiscoNexus1000vVSM to prepare for
> > > > > Nic[1507-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-169.254.2.23]
> > > > > 2013-07-15 12:09:12,562 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking BigSwitchVnsElement to prepare for
> > > > > Nic[1507-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-169.254.2.23]
> > > > > 2013-07-15 12:09:12,562 DEBUG [network.element.BigSwitchVnsElement]
> > > > > (consoleproxy-1:null) Checking if BigSwitchVnsElement can handle
> > > service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:12,562 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking VirtualRouter to prepare for
> > > > > Nic[1507-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-169.254.2.23]
> > > > > 2013-07-15 12:09:12,562 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking Ovs to prepare for
> > > > > Nic[1507-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-169.254.2.23]
> > > > > 2013-07-15 12:09:12,562 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking SecurityGroupProvider to prepare for
> > > > > Nic[1507-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-169.254.2.23]
> > > > > 2013-07-15 12:09:12,562 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking VpcVirtualRouter to prepare for
> > > > > Nic[1507-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-169.254.2.23]
> > > > > 2013-07-15 12:09:12,562 WARN
> > > [network.element.VpcVirtualRouterElement]
> > > > > (consoleproxy-1:null) Network Ntwk[202|Control|3] is not associated
> > > with
> > > > > any VPC
> > > > > 2013-07-15 12:09:12,566 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Lock is acquired for network id 201 as a part
> > of
> > > > > network implement
> > > > > 2013-07-15 12:09:12,566 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Network id=201 is already implemented
> > > > > 2013-07-15 12:09:12,567 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Lock is released for network id 201 as a part
> > of
> > > > > network implement
> > > > > 2013-07-15 12:09:12,585 DEBUG [network.guru.PodBasedNetworkGuru]
> > > > > (consoleproxy-1:null) Allocated a nic
> > > > >
> > > > NicProfile[1508-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-
> > > 192.168.2.184-null
> > > > > for VM[ConsoleProxy|v-378-VM]
> > > > > 2013-07-15 12:09:12,588 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking NiciraNvp to prepare for
> > > > > Nic[1508-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.184]
> > > > > 2013-07-15 12:09:12,589 DEBUG [network.element.NiciraNvpElement]
> > > > > (consoleproxy-1:null) Checking if NiciraNvpElement can handle
> service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:12,589 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking JuniperSRX to prepare for
> > > > > Nic[1508-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.184]
> > > > > 2013-07-15 12:09:12,589 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking Netscaler to prepare for
> > > > > Nic[1508-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.184]
> > > > > 2013-07-15 12:09:12,590 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking F5BigIP to prepare for
> > > > > Nic[1508-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.184]
> > > > > 2013-07-15 12:09:12,590 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking CiscoNexus1000vVSM to prepare for
> > > > > Nic[1508-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.184]
> > > > > 2013-07-15 12:09:12,590 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking BigSwitchVnsElement to prepare for
> > > > > Nic[1508-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.184]
> > > > > 2013-07-15 12:09:12,591 DEBUG [network.element.BigSwitchVnsElement]
> > > > > (consoleproxy-1:null) Checking if BigSwitchVnsElement can handle
> > > service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:12,591 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking VirtualRouter to prepare for
> > > > > Nic[1508-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.184]
> > > > > 2013-07-15 12:09:12,591 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking Ovs to prepare for
> > > > > Nic[1508-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.184]
> > > > > 2013-07-15 12:09:12,591 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking SecurityGroupProvider to prepare for
> > > > > Nic[1508-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.184]
> > > > > 2013-07-15 12:09:12,591 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (consoleproxy-1:null) Asking VpcVirtualRouter to prepare for
> > > > > Nic[1508-378-db45f1f8-1681-46bd-b31a-22b10ee369dd-192.168.2.184]
> > > > > 2013-07-15 12:09:12,591 WARN
> > > [network.element.VpcVirtualRouterElement]
> > > > > (consoleproxy-1:null) Network Ntwk[201|Management|2] is not
> > > associated
> > > > with
> > > > > any VPC
> > > > > 2013-07-15 12:09:12,594 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (consoleproxy-1:null) Checking if we need to prepare 1 volumes for
> > > > > VM[ConsoleProxy|v-378-VM]
> > > > > 2013-07-15 12:09:12,598 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (consoleproxy-1:null) Creating volume: Vol[378|vm=378|ROOT]
> > > > > 2013-07-15 12:09:12,598 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (consoleproxy-1:null) Trying to create in
> Pool[204|NetworkFilesystem]
> > > > > 2013-07-15 12:09:13,161 DEBUG
> > > > > [network.router.VirtualNetworkApplianceManagerImpl]
> > > > > (RouterStatusMonitor-1:null) Found 0 routers to update status.
> > > > > 2013-07-15 12:09:13,162 DEBUG
> > > > > [network.router.VirtualNetworkApplianceManagerImpl]
> > > > > (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> > > > > 2013-07-15 12:09:13,366 DEBUG
> > > > > [network.router.VirtualNetworkApplianceManagerImpl]
> > > > > (RouterStatusMonitor-1:null) Found 0 routers to update status.
> > > > > 2013-07-15 12:09:13,367 DEBUG
> > > > > [network.router.VirtualNetworkApplianceManagerImpl]
> > > > > (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> > > > > 2013-07-15 12:09:13,750 WARN  [xen.resource.CitrixResourceBase]
> > > > > (DirectAgent-60:null) destoryVDIbyNameLabel failed due to there
> are 0
> > > > VDIs
> > > > > with name cloud-e30ef955-b33d-47aa-8cdc-af8aa8b8a5a2
> > > > > 2013-07-15 12:09:13,751 WARN  [xen.resource.CitrixResourceBase]
> > > > > (DirectAgent-60:null) can not create vdi in sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a
> > > > > 2013-07-15 12:09:13,751 WARN  [xen.resource.CitrixResourceBase]
> > > > > (DirectAgent-60:null) Catch Exception
> > > > > com.cloud.utils.exception.CloudRuntimeException on
> > > > > host:5bbbc1e9-f78a-42fd-ab93-cf4bb141a2fe for template: nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/ due to
> > > > > com.cloud.utils.exception.CloudRuntimeException: can not create vdi
> > in
> > > sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a
> > > > > com.cloud.utils.exception.CloudRuntimeException: can not create vdi
> > in
> > > sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a
> > > > > at
> > > > >
> > > > >
> > > >
> > > com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_sec
> > > ondarystorage(CitrixResourceBase.java:2707)
> > > > >  at
> > > > >
> > > > >
> > > >
> > >
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResou
> > > rceBase.java:2729)
> > > > > at
> > > > >
> > > > >
> > > >
> > >
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(Citr
> > > ixResourceBase.java:501)
> > > > >  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.ac
> > > cess$101(ScheduledThreadPoolExecutor.java:165)
> > > > >  at
> > > > >
> > > > >
> > > >
> > > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.ru
> > > n(ScheduledThreadPoolExecutor.java:266)
> > > > > at
> > > > >
> > > > >
> > > >
> > >
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.jav
> > > a:1146)
> > > > >  at
> > > > >
> > > > >
> > > >
> > >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> > > va:615)
> > > > > at java.lang.Thread.run(Thread.java:679)
> > > > > 2013-07-15 12:09:13,755 DEBUG [agent.manager.DirectAgentAttache]
> > > > > (DirectAgent-60:null) Seq 7-1661993060: Response Received:
> > > > > 2013-07-15 12:09:13,755 DEBUG [agent.transport.Request]
> > > > > (DirectAgent-60:null) Seq 7-1661993060: Processing:  { Ans: ,
> MgmtId:
> > > > > 52231432591, via: 7, Ver: v1, Flags: 110,
> > > > >
> > > > >
> > > >
> > >
> [{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":fals
> > > e,"details":"Catch
> > > > > Exception com.cloud.utils.exception.CloudRuntimeException on
> > > > > host:5bbbc1e9-f78a-42fd-ab93-cf4bb141a2fe for template: nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/ due to
> > > > > com.cloud.utils.exception.CloudRuntimeException: can not create vdi
> > in
> > > sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a","wait":0}}] }
> > > > > 2013-07-15 12:09:13,756 DEBUG [agent.transport.Request]
> > > > (secstorage-1:null)
> > > > > Seq 7-1661993060: Received:  { Ans: , MgmtId: 52231432591, via: 7,
> > Ver:
> > > > v1,
> > > > > Flags: 110, { PrimaryStorageDownloadAnswer } }
> > > > > 2013-07-15 12:09:13,756 DEBUG [agent.manager.AgentManagerImpl]
> > > > > (secstorage-1:null) Details from executing class
> > > > > com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch
> > > > Exception
> > > > > com.cloud.utils.exception.CloudRuntimeException on
> > > > > host:5bbbc1e9-f78a-42fd-ab93-cf4bb141a2fe for template: nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/ due to
> > > > > com.cloud.utils.exception.CloudRuntimeException: can not create vdi
> > in
> > > sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a
> > > > > 2013-07-15 12:09:13,756 DEBUG [cloud.template.TemplateManagerImpl]
> > > > > (secstorage-1:null) Template 1 download to pool 204 failed due to
> > Catch
> > > > > Exception com.cloud.utils.exception.CloudRuntimeException on
> > > > > host:5bbbc1e9-f78a-42fd-ab93-cf4bb141a2fe for template: nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/ due to
> > > > > com.cloud.utils.exception.CloudRuntimeException: can not create vdi
> > in
> > > sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a
> > > > > 2013-07-15 12:09:13,757 DEBUG [cloud.template.TemplateManagerImpl]
> > > > > (secstorage-1:null) Downloading 1 via 7
> > > > > 2013-07-15 12:09:13,760 DEBUG [agent.manager.AgentAttache]
> > > > > (DirectAgent-60:null) Seq 7-1661993060: No more commands found
> > > > > 2013-07-15 12:09:13,762 DEBUG [agent.transport.Request]
> > > > (secstorage-1:null)
> > > > > Seq 7-1661993061: Sending  { Cmd , MgmtId: 52231432591, via: 7,
> Ver:
> > v1,
> > > > > Flags: 100111,
> > > > >
> > > > >
> > > >
> > > [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/483c879b
> > > -67a3-3830-9c87-1997efb60ed0","poolUuid":"483c879b-67a3-3830-9c87-
> > >
> 1997efb60ed0","poolId":204,"primaryPool":{"id":204,"uuid":"483c879b-67a3-
> > > 3830-9c87-
> > >
> 1997efb60ed0","host":"192.168.2.123","path":"/export/primary","port":2049
> > > ,"type":"NetworkFilesystem"},"secondaryStorageUrl":"nfs://
> > > > > 192.168.2.123/export/secondary","primaryStorageUrl":"nfs://
> > > > > 192.168.2.123/export/primary","url":"nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/
> > > > > ","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
> > > > > }
> > > > > 2013-07-15 12:09:13,762 DEBUG [agent.transport.Request]
> > > > (secstorage-1:null)
> > > > > Seq 7-1661993061: Executing:  { Cmd , MgmtId: 52231432591, via: 7,
> > Ver:
> > > > v1,
> > > > > Flags: 100111,
> > > > >
> > > > >
> > > >
> > > [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/483c879b
> > > -67a3-3830-9c87-1997efb60ed0","poolUuid":"483c879b-67a3-3830-9c87-
> > >
> 1997efb60ed0","poolId":204,"primaryPool":{"id":204,"uuid":"483c879b-67a3-
> > > 3830-9c87-
> > >
> 1997efb60ed0","host":"192.168.2.123","path":"/export/primary","port":2049
> > > ,"type":"NetworkFilesystem"},"secondaryStorageUrl":"nfs://
> > > > > 192.168.2.123/export/secondary","primaryStorageUrl":"nfs://
> > > > > 192.168.2.123/export/primary","url":"nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/
> > > > > ","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
> > > > > }
> > > > > 2013-07-15 12:09:13,766 DEBUG [agent.manager.DirectAgentAttache]
> > > > > (DirectAgent-27:null) Seq 7-1661993061: Executing request
> > > > > 2013-07-15 12:09:15,991 WARN  [xen.resource.CitrixResourceBase]
> > > > > (DirectAgent-27:null) destoryVDIbyNameLabel failed due to there
> are 0
> > > > VDIs
> > > > > with name cloud-80619082-2378-4e39-98b3-8f1a3094e0fe
> > > > > 2013-07-15 12:09:16,001 WARN  [xen.resource.CitrixResourceBase]
> > > > > (DirectAgent-27:null) can not create vdi in sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a
> > > > > 2013-07-15 12:09:16,002 WARN  [xen.resource.CitrixResourceBase]
> > > > > (DirectAgent-27:null) Catch Exception
> > > > > com.cloud.utils.exception.CloudRuntimeException on
> > > > > host:5bbbc1e9-f78a-42fd-ab93-cf4bb141a2fe for template: nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/ due to
> > > > > com.cloud.utils.exception.CloudRuntimeException: can not create vdi
> > in
> > > sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a
> > > > > com.cloud.utils.exception.CloudRuntimeException: can not create vdi
> > in
> > > sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a
> > > > > at
> > > > >
> > > > >
> > > >
> > > com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_sec
> > > ondarystorage(CitrixResourceBase.java:2707)
> > > > >  at
> > > > >
> > > > >
> > > >
> > >
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResou
> > > rceBase.java:2729)
> > > > > at
> > > > >
> > > > >
> > > >
> > >
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(Citr
> > > ixResourceBase.java:501)
> > > > >  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.ac
> > > cess$101(ScheduledThreadPoolExecutor.java:165)
> > > > >  at
> > > > >
> > > > >
> > > >
> > > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.ru
> > > n(ScheduledThreadPoolExecutor.java:266)
> > > > > at
> > > > >
> > > > >
> > > >
> > >
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.jav
> > > a:1146)
> > > > >  at
> > > > >
> > > > >
> > > >
> > >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> > > va:615)
> > > > > at java.lang.Thread.run(Thread.java:679)
> > > > > 2013-07-15 12:09:16,002 DEBUG [agent.manager.DirectAgentAttache]
> > > > > (DirectAgent-27:null) Seq 7-1661993061: Response Received:
> > > > > 2013-07-15 12:09:16,003 DEBUG [agent.transport.Request]
> > > > > (DirectAgent-27:null) Seq 7-1661993061: Processing:  { Ans: ,
> MgmtId:
> > > > > 52231432591, via: 7, Ver: v1, Flags: 110,
> > > > >
> > > > >
> > > >
> > >
> [{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":fals
> > > e,"details":"Catch
> > > > > Exception com.cloud.utils.exception.CloudRuntimeException on
> > > > > host:5bbbc1e9-f78a-42fd-ab93-cf4bb141a2fe for template: nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/ due to
> > > > > com.cloud.utils.exception.CloudRuntimeException: can not create vdi
> > in
> > > sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a","wait":0}}] }
> > > > > 2013-07-15 12:09:16,006 DEBUG [agent.transport.Request]
> > > > (secstorage-1:null)
> > > > > Seq 7-1661993061: Received:  { Ans: , MgmtId: 52231432591, via: 7,
> > Ver:
> > > > v1,
> > > > > Flags: 110, { PrimaryStorageDownloadAnswer } }
> > > > > 2013-07-15 12:09:16,006 DEBUG [agent.manager.AgentManagerImpl]
> > > > > (secstorage-1:null) Details from executing class
> > > > > com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch
> > > > Exception
> > > > > com.cloud.utils.exception.CloudRuntimeException on
> > > > > host:5bbbc1e9-f78a-42fd-ab93-cf4bb141a2fe for template: nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/ due to
> > > > > com.cloud.utils.exception.CloudRuntimeException: can not create vdi
> > in
> > > sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a
> > > > > 2013-07-15 12:09:16,006 DEBUG [cloud.template.TemplateManagerImpl]
> > > > > (secstorage-1:null) Template 1 download to pool 204 failed due to
> > Catch
> > > > > Exception com.cloud.utils.exception.CloudRuntimeException on
> > > > > host:5bbbc1e9-f78a-42fd-ab93-cf4bb141a2fe for template: nfs://
> > > > > 192.168.2.123/export/secondary/template/tmpl/1/1/ due to
> > > > > com.cloud.utils.exception.CloudRuntimeException: can not create vdi
> > in
> > > sr
> > > > > 525f2561-6b3e-e7c7-fff1-7c8a22c44f3a
> > > > > 2013-07-15 12:09:16,006 DEBUG [cloud.template.TemplateManagerImpl]
> > > > > (secstorage-1:null) Template 1 is not found on and can not be
> > > downloaded
> > > > to
> > > > > pool 204
> > > > > 2013-07-15 12:09:16,006 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (secstorage-1:null) Cannot use this pool
> Pool[204|NetworkFilesystem]
> > > > > because we can't propagate template Tmpl[1-VHD-routing-1
> > > > > 2013-07-15 12:09:16,008 DEBUG [agent.manager.AgentAttache]
> > > > > (DirectAgent-27:null) Seq 7-1661993061: No more commands found
> > > > > 2013-07-15 12:09:16,010 INFO  [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) Unable to contact resource.
> > > > > com.cloud.exception.StorageUnavailableException: Resource
> > > > [StoragePool:204]
> > > > > is unreachable: Unable to create Vol[383|vm=383|ROOT]
> > > > > at
> > > > >
> > > >
> > > com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:
> > > 3488)
> > > > >  at
> > > > >
> > > > >
> > > >
> > > com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineMa
> > > nagerImpl.java:748)
> > > > > at
> > > > >
> > > > >
> > > >
> > > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerIm
> > > pl.java:471)
> > > > >  at
> > > > >
> > > > >
> > > >
> > > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerIm
> > > pl.java:464)
> > > > > at
> > > > >
> > > > >
> > > >
> > > com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorag
> > > eVm(SecondaryStorageManagerImpl.java:264)
> > > > >  at
> > > > >
> > > > >
> > > >
> > > com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(
> > > SecondaryStorageManagerImpl.java:689)
> > > > > at
> > > > >
> > > > >
> > > >
> > > com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(S
> > > econdaryStorageManagerImpl.java:1300)
> > > > >  at
> > > > >
> > > > >
> > > >
> > > com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(Pre
> > > miumSecondaryStorageManagerImpl.java:121)
> > > > > at
> > > > >
> > > > >
> > > >
> > > com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(Pre
> > > miumSecondaryStorageManagerImpl.java:52)
> > > > >  at
> > > >
> > > com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java
> > > :104)
> > > > > at
> > > >
> > > com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.ja
> > > va:33)
> > > > >  at
> > > > >
> > > com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.j
> > > ava:81)
> > > > > at
> > > com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72
> > > )
> > > > >  at
> > > >
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> > > > > at
> > > > >
> > > >
> > >
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:35
> > > 1)
> > > > >  at
> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
> > > > > at
> > > > >
> > > > >
> > > >
> > > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.ac
> > > cess$201(ScheduledThreadPoolExecutor.java:165)
> > > > >  at
> > > > >
> > > > >
> > > >
> > > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.ru
> > > n(ScheduledThreadPoolExecutor.java:267)
> > > > > at
> > > > >
> > > > >
> > > >
> > >
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.jav
> > > a:1146)
> > > > >  at
> > > > >
> > > > >
> > > >
> > >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> > > va:615)
> > > > > at java.lang.Thread.run(Thread.java:679)
> > > > > 2013-07-15 12:09:16,012 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) Cleaning up resources for the vm
> > > > > VM[SecondaryStorageVm|s-383-VM] in Starting state
> > > > > 2013-07-15 12:09:16,013 DEBUG [agent.transport.Request]
> > > > (secstorage-1:null)
> > > > > Seq 7-1661993062: Sending  { Cmd , MgmtId: 52231432591, via: 7,
> Ver:
> > v1,
> > > > > Flags: 100111,
> > > > > [{"StopCommand":{"isProxy":false,"vmName":"s-383-VM","wait":0}}] }
> > > > > 2013-07-15 12:09:16,013 DEBUG [agent.transport.Request]
> > > > (secstorage-1:null)
> > > > > Seq 7-1661993062: Executing:  { Cmd , MgmtId: 52231432591, via: 7,
> > Ver:
> > > > v1,
> > > > > Flags: 100111,
> > > > > [{"StopCommand":{"isProxy":false,"vmName":"s-383-VM","wait":0}}] }
> > > > > 2013-07-15 12:09:16,013 DEBUG [agent.manager.DirectAgentAttache]
> > > > > (DirectAgent-61:null) Seq 7-1661993062: Executing request
> > > > > 2013-07-15 12:09:16,069 INFO  [xen.resource.CitrixResourceBase]
> > > > > (DirectAgent-61:null) VM does not exist on
> > > > > XenServer5bbbc1e9-f78a-42fd-ab93-cf4bb141a2fe
> > > > > 2013-07-15 12:09:16,069 DEBUG [agent.manager.DirectAgentAttache]
> > > > > (DirectAgent-61:null) Seq 7-1661993062: Response Received:
> > > > > 2013-07-15 12:09:16,069 DEBUG [agent.transport.Request]
> > > > > (DirectAgent-61:null) Seq 7-1661993062: Processing:  { Ans: ,
> MgmtId:
> > > > > 52231432591, via: 7, Ver: v1, Flags: 110,
> > > > > [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM does not
> > > > > exist","wait":0}}] }
> > > > > 2013-07-15 12:09:16,069 DEBUG [agent.manager.AgentAttache]
> > > > > (DirectAgent-61:null) Seq 7-1661993062: No more commands found
> > > > > 2013-07-15 12:09:16,069 DEBUG [agent.transport.Request]
> > > > (secstorage-1:null)
> > > > > Seq 7-1661993062: Received:  { Ans: , MgmtId: 52231432591, via: 7,
> > Ver:
> > > > v1,
> > > > > Flags: 110, { StopAnswer } }
> > > > > 2013-07-15 12:09:16,079 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking NiciraNvp to release
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:16,079 DEBUG [network.element.NiciraNvpElement]
> > > > > (secstorage-1:null) Checking if NiciraNvpElement can handle service
> > > > > Connectivity on network defaultGuestNetwork
> > > > > 2013-07-15 12:09:16,079 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking JuniperSRX to release
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:16,080 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Netscaler to release
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:16,080 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking F5BigIP to release
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:16,080 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking CiscoNexus1000vVSM to release
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:16,080 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking BigSwitchVnsElement to release
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:16,080 DEBUG [network.element.BigSwitchVnsElement]
> > > > > (secstorage-1:null) Checking if BigSwitchVnsElement can handle
> > service
> > > > > Connectivity on network defaultGuestNetwork
> > > > > 2013-07-15 12:09:16,080 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VirtualRouter to release
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:16,080 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Ovs to release
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:16,080 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking SecurityGroupProvider to release
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:16,080 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VpcVirtualRouter to release
> > > > > Nic[1525-383-6481cf60-9be7-403d-a53c-b514af71184d-192.168.2.200]
> > > > > 2013-07-15 12:09:16,084 DEBUG [network.guru.ControlNetworkGuru]
> > > > > (secstorage-1:null) Released nic:
> NicProfile[1526-383-null-null-null
> > > > > 2013-07-15 12:09:16,086 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking NiciraNvp to release
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,086 DEBUG [network.element.NiciraNvpElement]
> > > > > (secstorage-1:null) Checking if NiciraNvpElement can handle service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:16,086 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking JuniperSRX to release
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,086 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Netscaler to release
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,086 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking F5BigIP to release
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,086 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking CiscoNexus1000vVSM to release
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,086 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking BigSwitchVnsElement to release
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,086 DEBUG [network.element.BigSwitchVnsElement]
> > > > > (secstorage-1:null) Checking if BigSwitchVnsElement can handle
> > service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:16,086 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VirtualRouter to release
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,086 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Ovs to release
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,086 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking SecurityGroupProvider to release
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,086 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VpcVirtualRouter to release
> > > > > Nic[1526-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,091 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
> > > > > (secstorage-1:null) Releasing ip address for
> > > > > reservationId=6481cf60-9be7-403d-a53c-b514af71184d, instance=1527
> > > > > 2013-07-15 12:09:16,092 DEBUG [network.guru.PodBasedNetworkGuru]
> > > > > (secstorage-1:null) Released nic:
> NicProfile[1527-383-null-null-null
> > > > > 2013-07-15 12:09:16,094 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking NiciraNvp to release
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,094 DEBUG [network.element.NiciraNvpElement]
> > > > > (secstorage-1:null) Checking if NiciraNvpElement can handle service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:16,094 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking JuniperSRX to release
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,094 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Netscaler to release
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,094 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking F5BigIP to release
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,094 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking CiscoNexus1000vVSM to release
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,094 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking BigSwitchVnsElement to release
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,094 DEBUG [network.element.BigSwitchVnsElement]
> > > > > (secstorage-1:null) Checking if BigSwitchVnsElement can handle
> > service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:16,094 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VirtualRouter to release
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,094 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Ovs to release
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,094 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking SecurityGroupProvider to release
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,094 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VpcVirtualRouter to release
> > > > > Nic[1527-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,100 DEBUG [network.guru.StorageNetworkGuru]
> > > > > (secstorage-1:null) Release an storage ip 192.168.2.57
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking NiciraNvp to release
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,103 DEBUG [network.element.NiciraNvpElement]
> > > > > (secstorage-1:null) Checking if NiciraNvpElement can handle service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking JuniperSRX to release
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Netscaler to release
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking F5BigIP to release
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking CiscoNexus1000vVSM to release
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking BigSwitchVnsElement to release
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,103 DEBUG [network.element.BigSwitchVnsElement]
> > > > > (secstorage-1:null) Checking if BigSwitchVnsElement can handle
> > service
> > > > > Connectivity on network null
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VirtualRouter to release
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking Ovs to release
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking SecurityGroupProvider to release
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Asking VpcVirtualRouter to release
> > > > > Nic[1528-383-6481cf60-9be7-403d-a53c-b514af71184d-null]
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) Successfully released network resources for the
> > vm
> > > > > VM[SecondaryStorageVm|s-383-VM]
> > > > > 2013-07-15 12:09:16,103 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) Successfully cleanued up resources for the vm
> > > > > VM[SecondaryStorageVm|s-383-VM] in Starting state
> > > > > 2013-07-15 12:09:16,107 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) DeploymentPlanner allocation algorithm: random
> > > > > 2013-07-15 12:09:16,107 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Trying to allocate a host and storage pools
> from
> > > > dc:1,
> > > > > pod:1,cluster:null, requested cpu: 500, requested ram: 268435456
> > > > > 2013-07-15 12:09:16,107 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Is ROOT volume READY (pool already allocated)?:
> > No
> > > > > 2013-07-15 12:09:16,107 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Searching resources only under specified Pod: 1
> > > > > 2013-07-15 12:09:16,108 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Listing clusters in order of aggregate
> capacity,
> > that
> > > > > have (atleast one host with) enough CPU and RAM capacity under this
> > > Pod:
> > > > 1
> > > > > 2013-07-15 12:09:16,109 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) CPUOverprovisioningFactor considered: 1.0
> > > > > 2013-07-15 12:09:16,114 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Checking resources in Cluster: 3 under Pod: 1
> > > > > 2013-07-15 12:09:16,114 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1
> >  pod:1
> > > > >  cluster:3
> > > > > 2013-07-15 12:09:16,116 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1
> > hosts to
> > > > > check for allocation: [Host[-7-Routing]]
> > > > > 2013-07-15 12:09:16,118 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for
> allocation
> > > > after
> > > > > prioritization: [Host[-7-Routing]]
> > > > > 2013-07-15 12:09:16,118 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz,
> > > Ram=256
> > > > > 2013-07-15 12:09:16,118 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Host name: xenserver-01,
> > hostId:
> > > > 7
> > > > > is in avoid set, skipping this and trying other available hosts
> > > > > 2013-07-15 12:09:16,119 DEBUG [allocator.impl.FirstFitAllocator]
> > > > > (secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 0
> > > > suitable
> > > > > hosts
> > > > > 2013-07-15 12:09:16,119 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) No suitable hosts found
> > > > > 2013-07-15 12:09:16,119 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) No suitable hosts found under this Cluster: 3
> > > > > 2013-07-15 12:09:16,119 DEBUG [cloud.deploy.FirstFitPlanner]
> > > > > (secstorage-1:null) Could not find suitable Deployment Destination
> > for
> > > > this
> > > > > VM under any clusters, returning.
> > > > > 2013-07-15 12:09:16,125 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) VM state transitted from :Starting to Stopped
> > with
> > > > > event: OperationFailedvm's original host id: null new host id: null
> > host
> > > > id
> > > > > before state transition: 7
> > > > > 2013-07-15 12:09:16,129 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) Hosts's actual total CPU: 25608 and CPU after
> > > > applying
> > > > > overprovisioning: 25608
> > > > > 2013-07-15 12:09:16,129 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) release cpu from host: 7, old used:
> > 1000,reserved: 0,
> > > > > actual total: 25608, total with overprovisioning: 25608; new used:
> > > > > 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
> > > > > 2013-07-15 12:09:16,129 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) release mem from host: 7, old used:
> > > > > 1342177280,reserved: 0, total: 16199733312; new used:
> > > > > 1073741824,reserved:0; movedfromreserved:
> > > false,moveToReserveredfalse
> > > > > 2013-07-15 12:09:16,132 WARN
> > > > >  [storage.secondary.SecondaryStorageManagerImpl]
> (secstorage-1:null)
> > > > > Exception while trying to start secondary storage vm
> > > > > com.cloud.exception.InsufficientServerCapacityException: Unable to
> > > > create a
> > > > > deployment for VM[SecondaryStorageVm|s-383-VM]Scope=interface
> > > > > com.cloud.dc.DataCenter; id=1
> > > > >  at
> > > > >
> > > > >
> > > >
> > > com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineMa
> > > nagerImpl.java:728)
> > > > > at
> > > > >
> > > > >
> > > >
> > > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerIm
> > > pl.java:471)
> > > > >  at
> > > > >
> > > > >
> > > >
> > > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerIm
> > > pl.java:464)
> > > > > at
> > > > >
> > > > >
> > > >
> > > com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorag
> > > eVm(SecondaryStorageManagerImpl.java:264)
> > > > >  at
> > > > >
> > > > >
> > > >
> > > com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(
> > > SecondaryStorageManagerImpl.java:689)
> > > > > at
> > > > >
> > > > >
> > > >
> > > com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(S
> > > econdaryStorageManagerImpl.java:1300)
> > > > >  at
> > > > >
> > > > >
> > > >
> > > com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(Pre
> > > miumSecondaryStorageManagerImpl.java:121)
> > > > > at
> > > > >
> > > > >
> > > >
> > > com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(Pre
> > > miumSecondaryStorageManagerImpl.java:52)
> > > > >  at
> > > >
> > > com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java
> > > :104)
> > > > > at
> > > >
> > > com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.ja
> > > va:33)
> > > > >  at
> > > > >
> > > com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.j
> > > ava:81)
> > > > > at
> > > com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72
> > > )
> > > > >  at
> > > >
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> > > > > at
> > > > >
> > > >
> > >
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:35
> > > 1)
> > > > >  at
> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
> > > > > at
> > > > >
> > > > >
> > > >
> > > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.ac
> > > cess$201(ScheduledThreadPoolExecutor.java:165)
> > > > >  at
> > > > >
> > > > >
> > > >
> > > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.ru
> > > n(ScheduledThreadPoolExecutor.java:267)
> > > > > at
> > > > >
> > > > >
> > > >
> > >
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.jav
> > > a:1146)
> > > > >  at
> > > > >
> > > > >
> > > >
> > >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> > > va:615)
> > > > > at java.lang.Thread.run(Thread.java:679)
> > > > > 2013-07-15 12:09:16,136 INFO
> > > > >  [storage.secondary.SecondaryStorageManagerImpl]
> (secstorage-1:null)
> > > > Unable
> > > > > to start secondary storage vm for standby capacity, secStorageVm vm
> > Id :
> > > > > 383, will recycle it and start a new one
> > > > > 2013-07-15 12:09:16,137 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) VM is already stopped:
> > > > VM[SecondaryStorageVm|s-383-VM]
> > > > > 2013-07-15 12:09:16,140 DEBUG [cloud.capacity.CapacityManagerImpl]
> > > > > (secstorage-1:null) VM state transitted from :Stopped to Expunging
> > with
> > > > > event: ExpungeOperationvm's original host id: null new host id:
> null
> > host
> > > > > id before state transition: null
> > > > > 2013-07-15 12:09:16,142 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) Destroying vm VM[SecondaryStorageVm|s-383-VM]
> > > > > 2013-07-15 12:09:16,142 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) Cleaning up NICS
> > > > > 2013-07-15 12:09:16,142 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Cleaning network for vm: 383
> > > > > 2013-07-15 12:09:16,151 DEBUG [network.guru.DirectNetworkGuru]
> > > > > (secstorage-1:null) Deallocate network: networkId: 204, ip:
> > 192.168.2.200
> > > > > 2013-07-15 12:09:16,158 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Removed nic id=1525
> > > > > 2013-07-15 12:09:16,163 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Removed nic id=1526
> > > > > 2013-07-15 12:09:16,171 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Removed nic id=1527
> > > > > 2013-07-15 12:09:16,179 DEBUG [cloud.network.NetworkManagerImpl]
> > > > > (secstorage-1:null) Removed nic id=1528
> > > > > 2013-07-15 12:09:16,179 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (secstorage-1:null) Cleaning storage for vm: 383
> > > > > 2013-07-15 12:09:16,185 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (secstorage-1:null) Expunging Vol[383|vm=383|ROOT]
> > > > > 2013-07-15 12:09:16,187 DEBUG [cloud.storage.StorageManagerImpl]
> > > > > (secstorage-1:null) Marking volume that was never created as
> > destroyed:
> > > > > Vol[383|vm=383|ROOT]
> > > > > 2013-07-15 12:09:16,193 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > > > > (secstorage-1:null) Expunged VM[SecondaryStorageVm|s-383-VM]
> > > > > 2013-07-15 12:09:16,198 INFO
> > > > >  [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
> > > > (secstorage-1:null)
> > > > > Primary secondary storage is not even started, wait until next turn
> > > > >
> > > > >
> > > > > On Mon, Jul 15, 2013 at 4:40 PM, Rohit Yadav <
> rohityadav89@gmail.com
> > >
> > > > > wrote:
> > > > >
> > > > > > On Tue, Jul 16, 2013 at 12:40 AM, Bradley Hieber
> > > <mercsniper@gmail.com
> > > > > > >wrote:
> > > > > >
> > > > > > > I have the vhd-util in
> > > > > > > /usr/lib64/cloud/common/scripts/vm/hypervisor/xenserver/
> > > > > > > on the management server.  Is there another place it needs to
> be
> > or
> > > > > > reside
> > > > > > > on the xen server itself?
> > > > > > >
> > > > > > >
> > > > > > Yes you could, but you should not move it yourself. During the
> > build
> > > > > > process of ACS, vhd-util (external dep) if available in the paths
> > is
> > > > used
> > > > > > in the systemvm.iso bundle. When hosts are added to ACS, this iso
> > is
> > > > > > mounted and various scripts and tools are copied to systemvms and
> > > > > vhd-util
> > > > > > on host (AFAIK, correct me if the behaviour has changed :).
> > > > > >
> > > > > > HTH,
> > > > > > bhaisaab
> > > > > >
> > > > > >
> > > > > > > --
> > > > > > > Brad
> > > > > > >
> > > > > >
> > > > >
> > > > >
> > > > >
> > > > > --
> > > > > Brad
> > > > >
> > > >
> > >
> > >
> > >
> > > --
> > > Brad
> >
>
>
>
> --
> Brad
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message