Your allocator works fine. The problem is that your SSVM can’t import OVA into 
vcenter or it can’t download OVA from URL 
‘http://download.cloud.com/releases/2.2.0/CentOS5.3-x86_64.ova’
Check if SSVM can communicate to vcenter over TCP/443. Check if there is an 
error in vcenter when you submit the deploy job. Also check SSVM log by 
executing this from management server:
sudo ssh -i /var/cloudstack/management/.ssh/id_rsa  -p 3922 root@IP_OF_SSVM cat 
/var/log/cloud.log



On 9/19/16, 1:38 AM, "Cristian Ciobanu" <cristian.c@istream.today> wrote:

    Hello All,
    
     
    
              I'm working on a ACS 4.5.2 with VMware 5.5 using Advanced
    networking setup ( local storage), I don't have any issue till my first VM
    deploy, please see my logs.
    
     
    
    -        I don't see any issue for Proxy console, SSVM, Router, I also run
    the test on ssvm "for check ssvm" no issue found.
    
     
    
            
    
    ============================================================================
    ============================================================
    
    U4IsCAAB4cAAAEO9zcQB-AFAAAAAAdwQAAAAAeHNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgA
    BSgAFdmFsdWV4cQB-AFMAAAAAAAAAAXZyABdjb20uY2xvdWQuZGMuRGF0YUNlbnRlcrLxCuun53i
    -AgAAeHAA
    
    management-server.log:2016-09-19 03:53:34,771 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-64:ctx-97809d3f
    job-115/job-116) Publish async job-116 complete on message bus
    
    management-server.log:2016-09-19 03:53:34,771 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-64:ctx-97809d3f
    job-115/job-116) Wake up jobs related to job-116
    
    management-server.log:2016-09-19 03:53:34,771 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-64:ctx-97809d3f
    job-115/job-116) Update db status for job-116
    
    management-server.log:2016-09-19 03:53:34,772 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-64:ctx-97809d3f
    job-115/job-116) Wake up jobs joined with job-116 and disjoin all subjobs
    created from job- 116
    
    management-server.log:2016-09-19 03:53:34,775 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-64:ctx-97809d3f
    job-115/job-116) Done executing com.cloud.vm.VmWorkStart for job-116
    
    management-server.log:2016-09-19 03:53:34,775 INFO
    [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-64:ctx-97809d3f
    job-115/job-116) Remove job-116 from job monitoring
    
    management-server.log:2016-09-19 03:53:34,783 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-45:ctx-e9ced335 job-115
    ctx-77ab93c4) Sync job-118 execution on object VmWorkJobQueue.17
    
    management-server.log:2016-09-19 03:53:34,803 WARN
    [o.a.c.f.j.i.AsyncJobMonitor] (Timer-1:ctx-137019e3) Task (job-115) has been
    pending for 135 seconds
    
    management-server.log:2016-09-19 03:53:35,940 INFO
    [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Add job-118 into job monitoring
    
    management-server.log:2016-09-19 03:53:35,945 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Executing AsyncJobVO {id:118, userId: 2, accountId: 2,
    instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart,
    cmdInfo:
    rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9p
    ZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAlj
    bHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQA
    EkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-
    AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01h
    cDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAE
    SgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAAC
    AAAAAAAAAAIAAAAAAAAAEXQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBw
    cHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRmFjdG9ySQAJdGhyZXNo
    b2xkeHA_QAAAAAAADHcIAAAAEAAAAAF0AApWbVBhc3N3b3JkdAAcck8wQUJYUUFEbk5oZG1Wa1gz
    QmhjM04zYjNKa3hw, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0,
    resultCode: 0, result: null, initMsid: 345048629065, completeMsid: null,
    lastUpdated: null, lastPolled: null, created: Mon Sep 19 03:53:34 EDT 2016}
    
    management-server.log:2016-09-19 03:53:35,946 DEBUG
    [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Run VM work job: com.cloud.vm.VmWorkStart for VM 17, job
    origin: 115
    
    management-server.log:2016-09-19 03:53:35,947 DEBUG
    [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Execute VM work job:
    com.cloud.vm.VmWorkStart{"dcId":0,"rawParams":{"VmPassword":"rO0ABXQADnNhdmV
    kX3Bhc3N3b3Jk"},"userId":2,"accountId":2,"vmId":17,"handlerName":"VirtualMac
    hineManagerImpl"}
    
    management-server.log:2016-09-19 03:53:35,952 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) 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
    
    management-server.log:2016-09-19 03:53:35,952 DEBUG
    [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Successfully transitioned to start state for
    VM[User|i-2-17-VM] reservation id = 44b41991-1b70-4668-9c46-6baef3f27f2d
    
    management-server.log:2016-09-19 03:53:35,954 DEBUG
    [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Trying to deploy VM, vm has dcId: 1 and podId:
    1
    
    management-server.log:2016-09-19 03:53:35,954 DEBUG
    [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Deploy avoids pods: null, clusters: null,
    hosts: null
    
    management-server.log:2016-09-19 03:53:35,960 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Deploy avoids pods: [], clusters: [], hosts:
    []
    
    management-server.log:2016-09-19 03:53:35,960 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) DeploymentPlanner allocation algorithm:
    com.cloud.deploy.FirstFitPlanner@4a7a3b82
    
    management-server.log:2016-09-19 03:53:35,960 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Trying to allocate a host and storage pools
    from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 536870912
    
    management-server.log:2016-09-19 03:53:35,960 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Is ROOT volume READY (pool already
    allocated)?: No
    
    management-server.log:2016-09-19 03:53:35,961 DEBUG [c.c.d.FirstFitPlanner]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Searching
    resources only under specified Pod: 1
    
    management-server.log:2016-09-19 03:53:35,961 DEBUG [c.c.d.FirstFitPlanner]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Listing
    clusters in order of aggregate capacity, that have (atleast one host with)
    enough CPU and RAM capacity under this Pod: 1
    
    management-server.log:2016-09-19 03:53:35,962 DEBUG [c.c.d.FirstFitPlanner]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Removing
    from the clusterId list these clusters from avoid set: []
    
    management-server.log:2016-09-19 03:53:35,966 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Checking resources in Cluster: 1 under Pod: 1
    
    management-server.log:2016-09-19 03:53:35,966 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Looking for hosts in
    dc: 1  pod:1  cluster:1
    
    management-server.log:2016-09-19 03:53:35,968 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) FirstFitAllocator has
    1 hosts to check for allocation: [Host[-1-Routing]]
    
    management-server.log:2016-09-19 03:53:35,970 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Found 1 hosts for
    allocation after prioritization: [Host[-1-Routing]]
    
    management-server.log:2016-09-19 03:53:35,970 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Looking for
    speed=500Mhz, Ram=512
    
    management-server.log:2016-09-19 03:53:35,974 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Host: 1 has cpu
    capability (cpu:8, speed:2399) to support requested CPU: 1 and requested
    speed: 500
    
    management-server.log:2016-09-19 03:53:35,974 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Checking if host: 1
    has enough capacity for requested CPU: 500 and requested RAM: 536870912 ,
    cpuOverprovisioningFactor: 2.0
    
    management-server.log:2016-09-19 03:53:35,975 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Hosts's actual total
    CPU: 19192 and CPU after applying overprovisioning: 38384
    
    management-server.log:2016-09-19 03:53:35,975 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Free CPU: 36384 ,
    Requested CPU: 500
    
    management-server.log:2016-09-19 03:53:35,975 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Free RAM: 66356494336
    , Requested RAM: 536870912
    
    management-server.log:2016-09-19 03:53:35,975 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Host has enough CPU
    and RAM available
    
    management-server.log:2016-09-19 03:53:35,975 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) STATS: Can alloc CPU
    from host: 1, used: 2000, reserved: 0, actual total: 19192, total with
    overprovisioning: 38384; requested cpu:500,alloc_from_last_host?:false
    ,considerReservedCapacity?: true
    
    management-server.log:2016-09-19 03:53:35,975 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) STATS: Can alloc MEM
    from host: 1, used: 2147483648, reserved: 0, total: 68503977984; requested
    mem: 536870912,alloc_from_last_host?:false ,considerReservedCapacity?: true
    
    management-server.log:2016-09-19 03:53:35,975 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Found a suitable
    host, adding to list: 1
    
    management-server.log:2016-09-19 03:53:35,975 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Host Allocator
    returning 1 suitable hosts
    
    management-server.log:2016-09-19 03:53:35,977 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Checking suitable pools for volume (Id, Type):
    (17,ROOT)
    
    management-server.log:2016-09-19 03:53:35,977 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) We need to allocate new storagepool for this
    volume
    
    management-server.log:2016-09-19 03:53:35,977 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Calling StoragePoolAllocators to find suitable
    pools
    
    management-server.log:2016-09-19 03:53:35,977 DEBUG
    [o.a.c.s.a.LocalStoragePoolAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) LocalStoragePoolAllocator trying to find
    storage pool to fit the vm
    
    management-server.log:2016-09-19 03:53:35,978 DEBUG
    [o.a.c.s.a.AbstractStoragePoolAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Checking if storage pool is suitable, name:
    null ,poolId: 1
    
    management-server.log:2016-09-19 03:53:35,979 INFO
    [c.c.s.StorageManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Storage pool null (1) does not supply IOPS
    capacity, assuming enough capacity
    
    management-server.log:2016-09-19 03:53:35,980 DEBUG
    [c.c.s.StorageManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Checking pool 1 for storage, totalSize:
    1992327954432, usedBytes: 9364832256, usedPct: 0.004700447150363783, disable
    threshold: 0.85
    
    management-server.log:2016-09-19 03:53:35,983 DEBUG
    [c.c.s.StorageManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Found storage pool
    nsMyVMwareHOST.xxx-xxx-xx.net Local Storage of type VMFS with
    overprovisioning factor 2
    
    management-server.log:2016-09-19 03:53:35,983 DEBUG
    [c.c.s.StorageManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Total over provisioned capacity calculated is
    2 * 1992327954432
    
    management-server.log:2016-09-19 03:53:35,983 DEBUG
    [c.c.s.StorageManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Total capacity of the pool
    nsMyVMwareHOST.xxx-xxx-xx.net Local Storage id: 1 is 3984655908864
    
    management-server.log:2016-09-19 03:53:35,984 DEBUG
    [c.c.s.StorageManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Checking pool: 1 for volume allocation
    [Vol[17|vm=17|ROOT]], maxSize : 3984655908864, totalAllocatedSize :
    6291456000, askingSize : 2147483648, allocated disable threshold: 0.85
    
    management-server.log:2016-09-19 03:53:35,984 DEBUG
    [o.a.c.s.a.LocalStoragePoolAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) LocalStoragePoolAllocator returning 1 suitable
    storage pools
    
    management-server.log:2016-09-19 03:53:35,984 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Trying to find a potenial host and associated
    storage pools from the suitable host/pool lists for this VM
    
    management-server.log:2016-09-19 03:53:35,984 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Checking if host: 1 can access any suitable
    storage pool for volume: ROOT
    
    management-server.log:2016-09-19 03:53:35,985 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Host: 1 can access pool: 1
    
    management-server.log:2016-09-19 03:53:35,985 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Found a potential host id: 1 name:
    nsMyVMwareHOST.xxx-xxx-xx.net and associated storage pools for this VM
    
    management-server.log:2016-09-19 03:53:35,985 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) 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(Volume(17|ROOT-->Pool(1))]
    
    management-server.log:2016-09-19 03:53:35,985 DEBUG
    [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Deployment found  - P0=VM[User|i-2-17-VM],
    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(Volume(17|ROOT-->Pool(1))]
    
    management-server.log:2016-09-19 03:53:35,995 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) VM state transitted from :Starting to Starting
    with event: OperationRetryvm's original host id: null new host id: 1 host id
    before state transition: null
    
    management-server.log:2016-09-19 03:53:35,999 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Hosts's actual total CPU: 19192 and CPU after
    applying overprovisioning: 38384
    
    management-server.log:2016-09-19 03:53:35,999 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) We are allocating VM, increasing the used
    capacity of this host:1
    
    management-server.log:2016-09-19 03:53:35,999 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Current Used CPU: 2000 , Free CPU:36384
    ,Requested CPU: 500
    
    management-server.log:2016-09-19 03:53:35,999 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Current Used RAM: 2147483648 , Free
    RAM:66356494336 ,Requested RAM: 536870912
    
    management-server.log:2016-09-19 03:53:35,999 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) CPU STATS after allocation: for host: 1, old
    used: 2000, old reserved: 0, actual total: 19192, total with
    overprovisioning: 38384; new used:2500, reserved:0; requested
    cpu:500,alloc_from_last:false
    
    management-server.log:2016-09-19 03:53:35,999 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) RAM STATS after allocation: for host: 1, old
    used: 2147483648, old reserved: 0, total: 68503977984; new used: 2684354560,
    reserved: 0; requested mem: 536870912,alloc_from_last:false
    
    management-server.log:2016-09-19 03:53:36,001 DEBUG
    [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) VM is being created in podId: 1
    
    management-server.log:2016-09-19 03:53:36,002 DEBUG
    [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Network id=207 is already implemented
    
    management-server.log:2016-09-19 03:53:36,008 DEBUG [c.c.n.NetworkModelImpl]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Service
    SecurityGroup is not supported in the network id=207
    
    management-server.log:2016-09-19 03:53:36,010 DEBUG
    [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Changing active number of nics for network
    id=207 on 1
    
    management-server.log:2016-09-19 03:53:36,012 DEBUG
    [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Asking VirtualRouter to prepare for
    Nic[27-17-44b41991-1b70-4668-9c46-6baef3f27f2d-10.1.1.2]
    
    management-server.log:2016-09-19 03:53:36,018 DEBUG
    [c.c.n.r.VirtualNetworkApplianceManagerImpl]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Lock is
    acquired for network id 207 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(Volume(17|ROOT-->Pool(1))]
    
    management-server.log:2016-09-19 03:53:36,020 DEBUG
    [c.c.n.r.VirtualNetworkApplianceManagerImpl]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Lock is
    released for network id 207 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(Volume(17|ROOT-->Pool(1))]
    
    management-server.log:2016-09-19 03:53:36,023 DEBUG [c.c.n.NetworkModelImpl]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Service
    SecurityGroup is not supported in the network id=207
    
    management-server.log:2016-09-19 03:53:36,029 DEBUG [c.c.n.NetworkModelImpl]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Service
    SecurityGroup is not supported in the network id=207
    
    management-server.log:2016-09-19 03:53:36,032 DEBUG
    [c.c.n.r.VirtualNetworkApplianceManagerImpl]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Applying
    dhcp entry in network Ntwk[207|Guest|8]
    
    management-server.log:2016-09-19 03:53:36,040 DEBUG [c.c.a.t.Request]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Seq
    1-2058989454638450055: Sending  { Cmd , MgmtId: 345048629065, via:
    1(nsMyVMwareHOST.xxx-xxx-xx.net), Ver: v1, Flags: 100011,
    [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"02:00:5c:d5:00:09
    ","vmIpAddress":"10.1.1.2","vmName":"VM-7757bae6-2844-43b4-8ce8-02afd0baed2a
    ","defaultRouter":"10.1.1.1","defaultDns":"10.1.1.1","duid":"00:03:00:01:02:
    00:5c:d5:00:09","isDefault":true,"executeInSequence":false,"accessDetails":{
    "zone.network.type":"Advanced","router.guest.ip":"10.1.1.1","router.ip":"172
    .20.0.196","router.name":"r-13-VM"},"wait":0}}] }
    
    management-server.log:2016-09-19 03:53:36,041 DEBUG [c.c.a.t.Request]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Seq
    1-2058989454638450055: Executing:  { Cmd , MgmtId: 345048629065, via:
    1(nsMyVMwareHOST.xxx-xxx-xx.net), Ver: v1, Flags: 100011,
    [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"02:00:5c:d5:00:09
    ","vmIpAddress":"10.1.1.2","vmName":"VM-7757bae6-2844-43b4-8ce8-02afd0baed2a
    ","defaultRouter":"10.1.1.1","defaultDns":"10.1.1.1","duid":"00:03:00:01:02:
    00:5c:d5:00:09","isDefault":true,"executeInSequence":false,"accessDetails":{
    "zone.network.type":"Advanced","router.guest.ip":"10.1.1.1","router.ip":"172
    .20.0.196","router.name":"r-13-VM"},"wait":0}}] }
    
    management-server.log:2016-09-19 03:53:36,041 DEBUG
    [c.c.h.v.r.VmwareResource] (DirectAgent-229:ctx-885aee83
    nsMyVMwareHOST.xxx-xxx-xx.net, job-115/job-118, cmd: DhcpEntryCommand) Use
    router's private IP for SSH control. IP : 172.20.0.196
    
    management-server.log:2016-09-19 03:53:36,041 DEBUG
    [c.c.h.v.r.VmwareResource] (DirectAgent-229:ctx-885aee83
    nsMyVMwareHOST.xxx-xxx-xx.net, job-115/job-118, cmd: DhcpEntryCommand) Run
    command on VR: 172.20.0.196, script: edithosts.sh with args:  -m
    02:00:5c:d5:00:09 -4 10.1.1.2 -h VM-7757bae6-2844-43b4-8ce8-02afd0baed2a -d
    10.1.1.1 -n 10.1.1.1
    
    management-server.log:2016-09-19 03:53:36,255 DEBUG
    [c.c.h.v.r.VmwareResource] (DirectAgent-229:ctx-885aee83
    nsMyVMwareHOST.xxx-xxx-xx.net, job-115/job-118, cmd: DhcpEntryCommand)
    edithosts.sh execution result: true
    
    management-server.log:2016-09-19 03:53:36,257 DEBUG [c.c.a.t.Request]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Seq
    1-2058989454638450055: Received:  { Ans: , MgmtId: 345048629065, via: 1,
    Ver: v1, Flags: 10, { Answer } }
    
    management-server.log:2016-09-19 03:53:36,259 DEBUG [c.c.n.NetworkModelImpl]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Service
    SecurityGroup is not supported in the network id=207
    
    management-server.log:2016-09-19 03:53:36,261 DEBUG
    [c.c.n.r.VirtualNetworkApplianceManagerImpl]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Applying
    userdata and password entry in network Ntwk[207|Guest|8]
    
    management-server.log:2016-09-19 03:53:36,269 DEBUG [c.c.a.t.Request]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Seq
    1-2058989454638450056: Sending  { Cmd , MgmtId: 345048629065, via:
    1(nsMyVMwareHOST.xxx-xxx-xx.net), Ver: v1, Flags: 100011,
    [{"com.cloud.agent.api.routing.SavePasswordCommand":{,"vmIpAddress":"10.1.1.
    2","vmName":"VM-7757bae6-2844-43b4-8ce8-02afd0baed2a","executeInSequence":fa
    lse,"accessDetails":{"zone.network.type":"Advanced","router.name":"r-13-VM",
    "router.ip":"172.20.0.196","router.guest.ip":"10.1.1.1"},"wait":0}},{"com.cl
    oud.agent.api.routing.VmDataCommand":{"vmIpAddress":"10.1.1.2","vmName":"VM-
    7757bae6-2844-43b4-8ce8-02afd0baed2a","executeInSequence":false,"accessDetai
    ls":{"zone.network.type":"Advanced","router.name":"r-13-VM","router.ip":"172
    .20.0.196","router.guest.ip":"10.1.1.1"},"wait":0}}] }
    
    management-server.log:2016-09-19 03:53:36,270 DEBUG [c.c.a.t.Request]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Seq
    1-2058989454638450056: Executing:  { Cmd , MgmtId: 345048629065, via:
    1(nsMyVMwareHOST.xxx-xxx-xx.net), Ver: v1, Flags: 100011,
    [{"com.cloud.agent.api.routing.SavePasswordCommand":{,"vmIpAddress":"10.1.1.
    2","vmName":"VM-7757bae6-2844-43b4-8ce8-02afd0baed2a","executeInSequence":fa
    lse,"accessDetails":{"zone.network.type":"Advanced","router.name":"r-13-VM",
    "router.ip":"172.20.0.196","router.guest.ip":"10.1.1.1"},"wait":0}},{"com.cl
    oud.agent.api.routing.VmDataCommand":{"vmIpAddress":"10.1.1.2","vmName":"VM-
    7757bae6-2844-43b4-8ce8-02afd0baed2a","executeInSequence":false,"accessDetai
    ls":{"zone.network.type":"Advanced","router.name":"r-13-VM","router.ip":"172
    .20.0.196","router.guest.ip":"10.1.1.1"},"wait":0}}] }
    
    management-server.log:2016-09-19 03:53:36,270 DEBUG
    [c.c.h.v.r.VmwareResource] (DirectAgent-458:ctx-b33ce6a9
    nsMyVMwareHOST.xxx-xxx-xx.net, job-115/job-118, cmd: SavePasswordCommand)
    Use router's private IP for SSH control. IP : 172.20.0.196
    
    management-server.log:2016-09-19 03:53:36,271 DEBUG
    [c.c.h.v.r.VmwareResource] (DirectAgent-458:ctx-b33ce6a9
    nsMyVMwareHOST.xxx-xxx-xx.net, job-115/job-118, cmd: SavePasswordCommand)
    Run command on VR: 172.20.0.196, script: savepassword.sh with args: -v
    10.1.1.2 -p saved_password
    
    management-server.log:2016-09-19 03:53:36,452 DEBUG
    [c.c.h.v.r.VmwareResource] (DirectAgent-458:ctx-b33ce6a9
    nsMyVMwareHOST.xxx-xxx-xx.net, job-115/job-118, cmd: SavePasswordCommand)
    savepassword.sh execution result: true
    
    management-server.log:2016-09-19 03:53:36,453 DEBUG
    [c.c.h.v.r.VmwareResource] (DirectAgent-458:ctx-b33ce6a9
    nsMyVMwareHOST.xxx-xxx-xx.net, job-115/job-118, cmd: VmDataCommand) Use
    router's private IP for SSH control. IP : 172.20.0.196
    
    management-server.log:2016-09-19 03:53:36,454 DEBUG
    [c.c.h.v.r.VmwareResource] (DirectAgent-458:ctx-b33ce6a9
    nsMyVMwareHOST.xxx-xxx-xx.net, job-115/job-118, cmd: VmDataCommand) Run
    command on VR: 172.20.0.196, script: vmdata.py with args: -d
    eyIxMC4xLjEuMiI6W1sidXNlcmRhdGEiLCJ1c2VyLWRhdGEiLG51bGxdLFsibWV0YWRhdGEiLCJz
    ZXJ2aWNlLW9mZmVyaW5nIiwiU21hbGwgSW5zdGFuY2UiXSxbIm1ldGFkYXRhIiwiYXZhaWxhYmls
    aXR5LXpvbmUiLCJBTVMtWk9ORS0wMSJdLFsibWV0YWRhdGEiLCJsb2NhbC1pcHY0IiwiMTAuMS4x
    LjIiXSxbIm1ldGFkYXRhIiwibG9jYWwtaG9zdG5hbWUiLCJWTS03NzU3YmFlNi0yODQ0LTQzYjQt
    OGNlOC0wMmFmZDBiYWVkMmEiXSxbIm1ldGFkYXRhIiwicHVibGljLWlwdjQiLCIxNDkuNTYuMTY0
    LjM2Il0sWyJtZXRhZGF0YSIsInB1YmxpYy1ob3N0bmFtZSIsIjE0OS41Ni4xNjQuMzYiXSxbIm1l
    dGFkYXRhIiwiaW5zdGFuY2UtaWQiLCI3NzU3YmFlNi0yODQ0LTQzYjQtOGNlOC0wMmFmZDBiYWVk
    MmEiXSxbIm1ldGFkYXRhIiwidm0taWQiLCI3NzU3YmFlNi0yODQ0LTQzYjQtOGNlOC0wMmFmZDBi
    YWVkMmEiXSxbIm1ldGFkYXRhIiwicHVibGljLWtleXMiLG51bGxdLFsibWV0YWRhdGEiLCJjbG91
    ZC1pZGVudGlmaWVyIiwiQ2xvdWRTdGFjay17ZDYxNGRlMGQtNzM1OS00OWViLWIyNWEtNWNmYzZk
    YWQ5ZTI3fSJdXX0=
    
    management-server.log:2016-09-19 03:53:36,649 DEBUG
    [c.c.h.v.r.VmwareResource] (DirectAgent-458:ctx-b33ce6a9
    nsMyVMwareHOST.xxx-xxx-xx.net, job-115/job-118, cmd: VmDataCommand)
    vmdata.py execution result: true
    
    management-server.log:2016-09-19 03:53:36,651 DEBUG [c.c.a.t.Request]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Seq
    1-2058989454638450056: Received:  { Ans: , MgmtId: 345048629065, via: 1,
    Ver: v1, Flags: 10, { Answer, Answer } }
    
    management-server.log:2016-09-19 03:53:36,651 DEBUG [c.c.n.NetworkModelImpl]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Service
    SecurityGroup is not supported in the network id=207
    
    management-server.log:2016-09-19 03:53:36,652 DEBUG
    [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Checking if we need to prepare 1 volumes for
    VM[User|i-2-17-VM]
    
    management-server.log:2016-09-19 03:53:36,655 DEBUG
    [o.a.c.s.i.TemplateDataFactoryImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) template 7 is already in store:1, type:Image
    
    management-server.log:2016-09-19 03:53:36,656 DEBUG
    [o.a.c.s.d.PrimaryDataStoreImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Not found (templateId:7poolId:1) in
    template_spool_ref, persisting it
    
    management-server.log:2016-09-19 03:53:36,659 DEBUG
    [o.a.c.s.i.TemplateDataFactoryImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) template 7 is already in store:1, type:Primary
    
    management-server.log:2016-09-19 03:53:36,659 DEBUG
    [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Found template centos53-x64 in storage pool 1
    with VMTemplateStoragePool id: 13
    
    management-server.log:2016-09-19 03:53:36,660 DEBUG
    [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Acquire lock on VMTemplateStoragePool 13 with
    timeout 3600 seconds
    
    management-server.log:2016-09-19 03:53:36,660 INFO
    [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) lock is acquired for VMTemplateStoragePool 13
    
    management-server.log:2016-09-19 03:53:36,674 DEBUG
    [o.a.c.s.m.AncientDataMotionStrategy] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) copyAsync inspecting src type TEMPLATE
    copyAsync inspecting dest type TEMPLATE
    
    management-server.log:2016-09-19 03:53:36,685 DEBUG [c.c.a.t.Request]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Seq
    3-5867345889533625014: Sending  { Cmd , MgmtId: 345048629065, via:
    3(s-1-VM), Ver: v1, Flags: 100111,
    [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.
    cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/1/7/93482cae-
    314b-3b74-992a-4e02d313e2a3.ova","origUrl":"http://download.cloud.com/releas
    es/2.2.0/CentOS5.3-x86_64.ova","uuid":"e30d03ae-7dde-11e6-afcd-005056803f49"
    ,"id":7,"format":"OVA","accountId":1,"checksum":"f6f881b7f2292948d8494db837f
    e0f47","hvm":false,"displayText":"CentOS 5.3(64-bit) no GUI
    (vSphere)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://1
    72.20.0.2/home/secondary","_role":"Image"}},"name":"centos53-x64","hyperviso
    rType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObject
    TO":{"origUrl":"http://download.cloud.com/releases/2.2.0/CentOS5.3-x86_64.ov
    a","uuid":"e30d03ae-7dde-11e6-afcd-005056803f49","id":7,"format":"OVA","acco
    untId":1,"checksum":"f6f881b7f2292948d8494db837fe0f47","hvm":false,"displayT
    ext":"CentOS 5.3(64-bit) no GUI
    (vSphere)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataSt
    oreTO":{"uuid":"a7deda1f-33e5-401b-a760-b469582c1e4c","id":1,"poolType":"VMF
    S","host":"VMFS datastore:
    datastore-118","path":"datastore-118","port":0,"url":"VMFS://VMFS datastore:
    datastore-118/datastore-118/?ROLE=Primary&STOREUUID=a7deda1f-33e5-401b-a760-
    b469582c1e4c"}},"name":"centos53-x64","hypervisorType":"VMware"}},"executeIn
    Sequence":true,"options":{},"wait":10800}}] }
    
    management-server.log:2016-09-19 03:54:34,804 WARN
    [o.a.c.f.j.i.AsyncJobMonitor] (Timer-1:ctx-2498d21f) Task (job-115) has been
    pending for 195 seconds
    
    management-server.log:2016-09-19 03:54:39,792 DEBUG [c.c.a.t.Request]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Seq
    3-5867345889533625014: Received:  { Ans: , MgmtId: 345048629065, via: 3,
    Ver: v1, Flags: 110, { CopyCmdAnswer } }
    
    management-server.log:2016-09-19 03:54:39,798 INFO
    [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) releasing lock for VMTemplateStoragePool 13
    
    management-server.log:2016-09-19 03:54:39,798 DEBUG
    [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Unable to create Vol[17|vm=17|ROOT]:Failed to
    create a Vmware context, check the management server logs or the ssvm log
    for details
    
    management-server.log:2016-09-19 03:54:39,798 INFO
    [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Unable to contact resource.
    
    management-server.log:2016-09-19 03:54:39,800 DEBUG
    [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Cleaning up resources for the vm
    VM[User|i-2-17-VM] in Starting state
    
    management-server.log:2016-09-19 03:54:39,802 DEBUG [c.c.a.t.Request]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Seq
    1-2058989454638450060: Sending  { Cmd , MgmtId: 345048629065, via:
    1(nsMyVMwareHOST.xxx-xxx-xx.net), Ver: v1, Flags: 100111,
    [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":tru
    e,"checkBeforeCleanup":false,"vmName":"i-2-17-VM","wait":0}}] }
    
    management-server.log:2016-09-19 03:54:39,802 DEBUG [c.c.a.t.Request]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Seq
    1-2058989454638450060: Executing:  { Cmd , MgmtId: 345048629065, via:
    1(nsMyVMwareHOST.xxx-xxx-xx.net), Ver: v1, Flags: 100111,
    [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":tru
    e,"checkBeforeCleanup":false,"vmName":"i-2-17-VM","wait":0}}] }
    
    management-server.log:2016-09-19 03:54:39,803 INFO
    [c.c.h.v.r.VmwareResource] (DirectAgent-460:ctx-9fff909c
    nsMyVMwareHOST.xxx-xxx-xx.net, job-115/job-118, cmd: StopCommand) Executing
    resource StopCommand:
    {"isProxy":false,"executeInSequence":true,"checkBeforeCleanup":false,"vmName
    ":"i-2-17-VM","wait":0}
    
    management-server.log:2016-09-19 03:54:39,821 DEBUG [c.c.h.v.m.HostMO]
    (DirectAgent-460:ctx-9fff909c nsMyVMwareHOST.xxx-xxx-xx.net,
    job-115/job-118, cmd: StopCommand) find VM i-2-17-VM on host
    
    management-server.log:2016-09-19 03:54:39,821 INFO  [c.c.h.v.m.HostMO]
    (DirectAgent-460:ctx-9fff909c nsMyVMwareHOST.xxx-xxx-xx.net,
    job-115/job-118, cmd: StopCommand) VM i-2-17-VM not found in host cache
    
    management-server.log:2016-09-19 03:54:39,821 DEBUG [c.c.h.v.m.HostMO]
    (DirectAgent-460:ctx-9fff909c nsMyVMwareHOST.xxx-xxx-xx.net,
    job-115/job-118, cmd: StopCommand) load VM cache on host
    
    management-server.log:2016-09-19 03:54:39,832 INFO
    [c.c.h.v.r.VmwareResource] (DirectAgent-460:ctx-9fff909c
    nsMyVMwareHOST.xxx-xxx-xx.net, job-115/job-118, cmd: StopCommand) VM
    i-2-17-VM is no longer in vSphere
    
    management-server.log:2016-09-19 03:54:39,833 DEBUG [c.c.a.t.Request]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Seq
    1-2058989454638450060: Received:  { Ans: , MgmtId: 345048629065, via: 1,
    Ver: v1, Flags: 110, { StopAnswer } }
    
    management-server.log:2016-09-19 03:54:39,837 DEBUG [c.c.n.NetworkModelImpl]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Service
    SecurityGroup is not supported in the network id=207
    
    management-server.log:2016-09-19 03:54:39,839 DEBUG
    [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Changing active number of nics for network
    id=207 on -1
    
    management-server.log:2016-09-19 03:54:39,842 DEBUG
    [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Asking VirtualRouter to release
    NicProfile[27-17-44b41991-1b70-4668-9c46-6baef3f27f2d-10.1.1.2-null
    
    management-server.log:2016-09-19 03:54:39,842 DEBUG
    [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Successfully released network resources for
    the vm VM[User|i-2-17-VM]
    
    management-server.log:2016-09-19 03:54:39,842 DEBUG
    [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Successfully cleanued up resources for the vm
    VM[User|i-2-17-VM] in Starting state
    
    management-server.log:2016-09-19 03:54:39,847 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Deploy avoids pods: [], clusters: [], hosts:
    [1]
    
    management-server.log:2016-09-19 03:54:39,847 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) DeploymentPlanner allocation algorithm:
    com.cloud.deploy.FirstFitPlanner@4a7a3b82
    
    management-server.log:2016-09-19 03:54:39,848 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Trying to allocate a host and storage pools
    from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 536870912
    
    management-server.log:2016-09-19 03:54:39,848 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Is ROOT volume READY (pool already
    allocated)?: No
    
    management-server.log:2016-09-19 03:54:39,848 DEBUG [c.c.d.FirstFitPlanner]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Searching
    resources only under specified Pod: 1
    
    management-server.log:2016-09-19 03:54:39,848 DEBUG [c.c.d.FirstFitPlanner]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Listing
    clusters in order of aggregate capacity, that have (atleast one host with)
    enough CPU and RAM capacity under this Pod: 1
    
    management-server.log:2016-09-19 03:54:39,849 DEBUG [c.c.d.FirstFitPlanner]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Removing
    from the clusterId list these clusters from avoid set: []
    
    management-server.log:2016-09-19 03:54:39,853 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Checking resources in Cluster: 1 under Pod: 1
    
    management-server.log:2016-09-19 03:54:39,853 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Looking for hosts in
    dc: 1  pod:1  cluster:1
    
    management-server.log:2016-09-19 03:54:39,855 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) FirstFitAllocator has
    1 hosts to check for allocation: [Host[-1-Routing]]
    
    management-server.log:2016-09-19 03:54:39,857 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Found 1 hosts for
    allocation after prioritization: [Host[-1-Routing]]
    
    management-server.log:2016-09-19 03:54:39,857 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Looking for
    speed=500Mhz, Ram=512
    
    management-server.log:2016-09-19 03:54:39,857 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Host name:
    nsMyVMwareHOST.xxx-xxx-xx.net, hostId: 1 is in avoid set, skipping this and
    trying other available hosts
    
    management-server.log:2016-09-19 03:54:39,857 DEBUG
    [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f FirstFitRoutingAllocator) Host Allocator
    returning 0 suitable hosts
    
    management-server.log:2016-09-19 03:54:39,857 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) No suitable hosts found
    
    management-server.log:2016-09-19 03:54:39,857 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) No suitable hosts found under this Cluster: 1
    
    management-server.log:2016-09-19 03:54:39,858 DEBUG
    [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Could not find suitable Deployment Destination
    for this VM under any clusters, returning.
    
    management-server.log:2016-09-19 03:54:39,858 DEBUG [c.c.d.FirstFitPlanner]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Searching
    resources only under specified Pod: 1
    
    management-server.log:2016-09-19 03:54:39,858 DEBUG [c.c.d.FirstFitPlanner]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Listing
    clusters in order of aggregate capacity, that have (atleast one host with)
    enough CPU and RAM capacity under this Pod: 1
    
    management-server.log:2016-09-19 03:54:39,859 DEBUG [c.c.d.FirstFitPlanner]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) Removing
    from the clusterId list these clusters from avoid set: [1]
    
    management-server.log:2016-09-19 03:54:39,860 DEBUG [c.c.d.FirstFitPlanner]
    (Work-Job-Executor-65:ctx-5592b640 job-115/job-118 ctx-acb9e21f) No clusters
    found after removing disabled clusters and clusters in avoid list,
    returning.
    
    management-server.log:2016-09-19 03:54:39,864 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) VM state transitted from :Starting to Stopped
    with event: OperationFailedvm's original host id: null new host id: null
    host id before state transition: 1
    
    management-server.log:2016-09-19 03:54:39,867 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Hosts's actual total CPU: 19192 and CPU after
    applying overprovisioning: 38384
    
    management-server.log:2016-09-19 03:54:39,867 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Hosts's actual total RAM: 34251988992 and RAM
    after applying overprovisioning: 68503977984
    
    management-server.log:2016-09-19 03:54:39,867 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) release cpu from host: 1, old used:
    2500,reserved: 0, actual total: 19192, total with overprovisioning: 38384;
    new used: 2000,reserved:0; movedfromreserved: false,moveToReserveredfalse
    
    management-server.log:2016-09-19 03:54:39,867 DEBUG
    [c.c.c.CapacityManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) release mem from host: 1, old used:
    2684354560,reserved: 0, total: 68503977984; new used: 2147483648,reserved:0;
    movedfromreserved: false,moveToReserveredfalse
    
    management-server.log:2016-09-19 03:54:39,874 ERROR
    [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Invocation exception, caused by:
    com.cloud.exception.InsufficientServerCapacityException: Unable to create a
    deployment for VM[User|i-2-17-VM]Scope=interface com.cloud.dc.DataCenter;
    id=1
    
    management-server.log:2016-09-19 03:54:39,875 INFO
    [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118 ctx-acb9e21f) Rethrow exception
    com.cloud.exception.InsufficientServerCapacityException: Unable to create a
    deployment for VM[User|i-2-17-VM]Scope=interface com.cloud.dc.DataCenter;
    id=1
    
    management-server.log:2016-09-19 03:54:39,875 DEBUG
    [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Done with run of VM work job: com.cloud.vm.VmWorkStart for
    VM 17, job origin: 115
    
    management-server.log:2016-09-19 03:54:39,875 ERROR
    [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Unable to complete AsyncJobVO {id:118, userId: 2,
    accountId: 2, instanceType: null, instanceId: null, cmd:
    com.cloud.vm.VmWorkStart, cmdInfo:
    rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9p
    ZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAlj
    bHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQA
    EkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-
    AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01h
    cDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAE
    SgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAAC
    AAAAAAAAAAIAAAAAAAAAEXQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBw
    cHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRmFjdG9ySQAJdGhyZXNo
    b2xkeHA_QAAAAAAADHcIAAAAEAAAAAF0AApWbVBhc3N3b3JkdAAcck8wQUJYUUFEbk5oZG1Wa1gz
    QmhjM04zYjNKa3hw, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0,
    resultCode: 0, result: null, initMsid: 345048629065, completeMsid: null,
    lastUpdated: null, lastPolled: null, created: Mon Sep 19 03:53:34 EDT 2016},
    job origin:115
    
    management-server.log:2016-09-19 03:54:39,876 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Complete async job-118, jobStatus: FAILED, resultCode: 0,
    result:
    rO0ABXNyADdjb20uY2xvdWQuZXhjZXB0aW9uLkluc3VmZmljaWVudFNlcnZlckNhcGFjaXR5RXhj
    ZXB0aW9uAAAAAFZNT3ACAAFaABVhZmZpbml0eUdyb3Vwc0FwcGxpZWR4cgAxY29tLmNsb3VkLmV4
    Y2VwdGlvbi5JbnN1ZmZpY2llbnRDYXBhY2l0eUV4Y2VwdGlvbgAAAABWTU91AgACTAACaWR0ABBM
    amF2YS9sYW5nL0xvbmc7TAAFc2NvcGV0ABFMamF2YS9sYW5nL0NsYXNzO3hyACJjb20uY2xvdWQu
    ZXhjZXB0aW9uLkNsb3VkRXhjZXB0aW9ueeiOG_HkRMcCAAJMAAtjc0Vycm9yQ29kZXQAE0xqYXZh
    L2xhbmcvSW50ZWdlcjtMAAZpZExpc3R0ABVMamF2YS91dGlsL0FycmF5TGlzdDt4cgATamF2YS5s
    YW5nLkV4Y2VwdGlvbtD9Hz4aOxzEAgAAeHIAE2phdmEubGFuZy5UaHJvd2FibGXVxjUnOXe4ywMA
    BEwABWNhdXNldAAVTGphdmEvbGFuZy9UaHJvd2FibGU7TAANZGV0YWlsTWVzc2FnZXQAEkxqYXZh
    L2xhbmcvU3RyaW5nO1sACnN0YWNrVHJhY2V0AB5bTGphdmEvbGFuZy9TdGFja1RyYWNlRWxlbWVu
    dDtMABRzdXBwcmVzc2VkRXhjZXB0aW9uc3QAEExqYXZhL3V0aWwvTGlzdDt4cHEAfgANdAA0VW5h
    YmxlIHRvIGNyZWF0ZSBhIGRlcGxveW1lbnQgZm9yIFZNW1VzZXJ8aS0yLTE3LVZNXXVyAB5bTGph
    dmEubGFuZy5TdGFja1RyYWNlRWxlbWVudDsCRio8PP0iOQIAAHhwAAAAFHNyABtqYXZhLmxhbmcu
    U3RhY2tUcmFjZUVsZW1lbnRhCcWaJjbdhQIABEkACmxpbmVOdW1iZXJMAA5kZWNsYXJpbmdDbGFz
    c3EAfgAKTAAIZmlsZU5hbWVxAH4ACkwACm1ldGhvZE5hbWVxAH4ACnhwAAADs3QAJmNvbS5jbG91
    ZC52bS5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsdAAeVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1w
    bC5qYXZhdAAQb3JjaGVzdHJhdGVTdGFydHNxAH4AEQAAEYFxAH4AE3EAfgAUcQB-ABVzcQB-ABH_
    ____dAAmc3VuLnJlZmxlY3QuR2VuZXJhdGVkTWV0aG9kQWNjZXNzb3IzODBwdAAGaW52b2tlc3EA
    fgARAAAAK3QAKHN1bi5yZWZsZWN0LkRlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGx0ACFEZWxl
    Z2F0aW5nTWV0aG9kQWNjZXNzb3JJbXBsLmphdmFxAH4AGXNxAH4AEQAAAl50ABhqYXZhLmxhbmcu
    cmVmbGVjdC5NZXRob2R0AAtNZXRob2QuamF2YXEAfgAZc3EAfgARAAAAa3QAImNvbS5jbG91ZC52
    bS5WbVdvcmtKb2JIYW5kbGVyUHJveHl0ABpWbVdvcmtKb2JIYW5kbGVyUHJveHkuamF2YXQAD2hh
    bmRsZVZtV29ya0pvYnNxAH4AEQAAEh1xAH4AE3EAfgAUcQB-ACNzcQB-ABEAAABndAAgY29tLmNs
    b3VkLnZtLlZtV29ya0pvYkRpc3BhdGNoZXJ0ABhWbVdvcmtKb2JEaXNwYXRjaGVyLmphdmF0AAZy
    dW5Kb2JzcQB-ABEAAAIZdAA_b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmZyYW1ld29yay5qb2JzLmlt
    cGwuQXN5bmNKb2JNYW5hZ2VySW1wbCQ1dAAYQXN5bmNKb2JNYW5hZ2VySW1wbC5qYXZhdAAMcnVu
    SW5Db250ZXh0c3EAfgARAAAAMXQAPm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRl
    eHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZSQxdAAbTWFuYWdlZENvbnRleHRSdW5uYWJsZS5qYXZh
    dAADcnVuc3EAfgARAAAAOHQAQm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQu
    aW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHQkMXQAGkRlZmF1bHRNYW5hZ2VkQ29udGV4dC5qYXZh
    dAAEY2FsbHNxAH4AEQAAAGd0AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0
    LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0cQB-ADN0AA9jYWxsV2l0aENvbnRleHRzcQB-ABEA
    AAA1cQB-ADZxAH4AM3QADnJ1bldpdGhDb250ZXh0c3EAfgARAAAALnQAPG9yZy5hcGFjaGUuY2xv
    dWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZXEAfgAvcQB-ADBz
    cQB-ABEAAAHucQB-ACpxAH4AK3EAfgAwc3EAfgARAAAB13QALmphdmEudXRpbC5jb25jdXJyZW50
    LkV4ZWN1dG9ycyRSdW5uYWJsZUFkYXB0ZXJ0AA5FeGVjdXRvcnMuamF2YXEAfgA0c3EAfgARAAAB
    BnQAH2phdmEudXRpbC5jb25jdXJyZW50LkZ1dHVyZVRhc2t0AA9GdXR1cmVUYXNrLmphdmFxAH4A
    MHNxAH4AEQAABHl0ACdqYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3J0ABdU
    aHJlYWRQb29sRXhlY3V0b3IuamF2YXQACXJ1bldvcmtlcnNxAH4AEQAAAmd0AC5qYXZhLnV0aWwu
    Y29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3IkV29ya2VycQB-AEVxAH4AMHNxAH4AEQAAAul0
    ABBqYXZhLmxhbmcuVGhyZWFkdAALVGhyZWFkLmphdmFxAH4AMHNyACZqYXZhLnV0aWwuQ29sbGVj
    dGlvbnMkVW5tb2RpZmlhYmxlTGlzdPwPJTG17I4QAgABTAAEbGlzdHEAfgAMeHIALGphdmEudXRp
    bC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVDb2xsZWN0aW9uGUIAgMte9x4CAAFMAAFjdAAWTGph
    dmEvdXRpbC9Db2xsZWN0aW9uO3hwc3IAE2phdmEudXRpbC5BcnJheUxpc3R4gdIdmcdhnQMAAUkA
    BHNpemV4cAAAAAB3BAAAAAB4cQB-AFF4c3IAEWphdmEubGFuZy5JbnRlZ2VyEuKgpPeBhzgCAAFJ
    AAV2YWx1ZXhyABBqYXZhLmxhbmcuTnVtYmVyhqyVHQuU4IsCAAB4cAAAEO9zcQB-AFAAAAAAdwQA
    AAAAeHNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cQB-AFMAAAAAAAAAAXZy
    ABdjb20uY2xvdWQuZGMuRGF0YUNlbnRlcrLxCuun53i-AgAAeHAA
    
    management-server.log:2016-09-19 03:54:39,877 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Publish async job-118 complete on message bus
    
    management-server.log:2016-09-19 03:54:39,877 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Wake up jobs related to job-118
    
    management-server.log:2016-09-19 03:54:39,877 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Update db status for job-118
    
    management-server.log:2016-09-19 03:54:39,877 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Wake up jobs joined with job-118 and disjoin all subjobs
    created from job- 118
    
    management-server.log:2016-09-19 03:54:39,880 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Done executing com.cloud.vm.VmWorkStart for job-118
    
    management-server.log:2016-09-19 03:54:39,881 INFO
    [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-65:ctx-5592b640
    job-115/job-118) Remove job-118 from job monitoring
    
    management-server.log:2016-09-19 03:54:39,886 DEBUG
    [c.c.v.UserVmManagerImpl] (API-Job-Executor-45:ctx-e9ced335 job-115
    ctx-77ab93c4) Destroying vm VM[User|i-2-17-VM] as it failed to create on
    Host with Id:null
    
    management-server.log:2016-09-19 03:54:39,889 DEBUG
    [c.c.c.CapacityManagerImpl] (API-Job-Executor-45:ctx-e9ced335 job-115
    ctx-77ab93c4) VM state transitted from :Stopped to Error with event:
    OperationFailedToErrorvm's original host id: null new host id: null host id
    before state transition: null
    
    management-server.log:2016-09-19 03:54:39,905 DEBUG
    [c.c.u.AccountManagerImpl] (API-Job-Executor-45:ctx-e9ced335 job-115
    ctx-77ab93c4) Access granted to
    Acct[f928b8cc-7dde-11e6-afcd-005056803f49-admin] to Domain:1/ by
    AffinityGroupAccessChecker
    
    management-server.log:2016-09-19 03:54:39,909 WARN  [o.a.c.alerts]
    (API-Job-Executor-45:ctx-e9ced335 job-115 ctx-77ab93c4)  alertType:: 8 //
    dataCenterId:: 1 // podId:: 1 // clusterId:: null // message:: Failed to
    deploy Vm with Id: 17, on Host with Id: null
    
    management-server.log:2016-09-19 03:54:39,920 ERROR
    [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-45:ctx-e9ced335 job-115)
    Unexpected exception while executing
    org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin
    
    management-server.log:2016-09-19 03:54:39,921 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-45:ctx-e9ced335 job-115)
    Complete async job-115, jobStatus: FAILED, resultCode: 530, result:
    org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"er
    rorcode":530,"errortext":"Unable to start a VM due to insufficient
    capacity"}
    
    management-server.log:2016-09-19 03:54:39,921 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-45:ctx-e9ced335 job-115)
    Publish async job-115 complete on message bus
    
    management-server.log:2016-09-19 03:54:39,922 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-45:ctx-e9ced335 job-115)
    Wake up jobs related to job-115
    
    management-server.log:2016-09-19 03:54:39,922 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-45:ctx-e9ced335 job-115)
    Update db status for job-115
    
    management-server.log:2016-09-19 03:54:39,922 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-45:ctx-e9ced335 job-115)
    Wake up jobs joined with job-115 and disjoin all subjobs created from job-
    115
    
    management-server.log:2016-09-19 03:54:39,924 DEBUG
    [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-45:ctx-e9ced335 job-115)
    Done executing org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin
    for job-115
    
    management-server.log:2016-09-19 03:54:39,924 INFO
    [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-45:ctx-e9ced335 job-115)
    Remove job-115 from job monitoring
    
     
    
     
    
     
    
     
    
    Regards,
    
    Cristian
    
     
    
    

Reply via email to