cloudstack-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From borisstoyanov <...@git.apache.org>
Subject [GitHub] cloudstack issue #1813: CLOUDSTACK-9604: Root disk resize support for VMware...
Date Sat, 04 Mar 2017 20:47:15 GMT
Github user borisstoyanov commented on the issue:

    https://github.com/apache/cloudstack/pull/1813
  
    Hi @serg38 , 
    
    Here's the management log: 
    ```
    2017-03-04 20:43:40,972 INFO  [c.c.h.v.r.VmwareResource] (DirectAgent-249:ctx-585f426d
10.2.2.73, job-29/job-32, cmd: StartCommand) (logid:b0dca526) Found existing disk info from
volume path: ROOT-3
    2017-03-04 20:43:40,972 ERROR [c.c.h.v.r.VmwareResource] (DirectAgent-249:ctx-585f426d
10.2.2.73, job-29/job-32, cmd: StartCommand) (logid:b0dca526) Unsupported Disk chain length
2
    2017-03-04 20:43:40,972 INFO  [c.c.h.v.u.VmwareHelper] (DirectAgent-249:ctx-585f426d 10.2.2.73,
job-29/job-32, cmd: StartCommand) (logid:b0dca526) [ignored]failed toi get message for exception:
Unsupported Disk chain length 2
    2017-03-04 20:43:40,975 WARN  [c.c.h.v.r.VmwareResource] (DirectAgent-249:ctx-585f426d
10.2.2.73, job-29/job-32, cmd: StartCommand) (logid:b0dca526) StartCommand failed due to Exception:
java.lang.Exception
    Message: Unsupported Disk chain length 2
    
    java.lang.Exception: Unsupported Disk chain length 2
    	at com.cloud.hypervisor.vmware.resource.VmwareResource.resizeRootDisk(VmwareResource.java:2106)
    	at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2029)
    	at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:467)
    	at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315)
    	at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
    	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
    	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
    	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
    	at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
    	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    	at java.lang.Thread.run(Thread.java:745)
    2017-03-04 20:43:40,975 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-249:ctx-585f426d)
(logid:b0dca526) Seq 1-6353453174312927730: Response Received:
    2017-03-04 20:43:40,976 DEBUG [c.c.a.t.Request] (DirectAgent-249:ctx-585f426d) (logid:b0dca526)
Seq 1-6353453174312927730: Processing:  { Ans: , MgmtId: 7267420276525, via: 1(10.2.2.73),
Ver: v1, Flags: 10, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":3,"name":"i-4-3-VM","bootloader":"HVM","type":"User","cpus":1,"minSpeed":50,"maxSpeed":100,"minRam":268435456,"maxRam":268435456,"hostName":"testvm","arch":"x86_64","os":"CentOS
5.3 (64-bit)","platformEmulator":"centos64Guest","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"pztIl7EL8AvGJtkrL8TuMQ","params":{"deployvm":"true","dataDiskController":"osdefault","memoryOvercommitRatio":"1.0","Message.ReservedCapacityFreed.Flag":"false","nestedVirtualizationFlag":"false","rootdisksize":"4","cpuOvercommitRatio":"2.0","vmware.reserve.mem":"false","vmware.reserve.cpu":"false","nicAdapter":"E1000","rootDiskController":"ide"},"uuid":"125b41bb-2d1f-4ab5-8bc4-493f4873fe86","disks":[{"data":{"
 org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"abf2b785-936b-40f8-91b0-0e7f62d3620f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"bdcf18cf-79d5-3459-a681-225d15719513","id":1,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/pr1813-t931-vmware-55u3/pr1813-t931-vmware-55u3-esxi-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/pr1813-t931-vmware-55u3/pr1813-t931-vmware-55u3-esxi-pri1/?ROLE=Primary&STOREUUID=bdcf18cf-79d5-3459-a681-225d15719513","isManaged":false}},"name":"ROOT-3","size":4294967296,"path":"ROOT-3","volumeId":3,"vmName":"i-4-3-VM","accountId":4,"format":"OVA","provisioningType":"THIN","id":3,"deviceId":0,"bytesReadRate":0,"bytesWriteRate":0,"iopsReadRate":0,"iopsWriteRate":0,"hypervisorType":"VMware"}},"diskSeq":0,"path":"ROOT-3","type":"ROOT","_details":{"storageHost":"10.2.0.16","managed":"false","storagePort":"2049","volumeSize":"4294967296"}},{"data":{"org.apache.clo
 udstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":false,"nicUuid":"1de3e11d-057c-4d5d-9a06-0bed9686efbd","uuid":"ed0b21f4-04a2-442d-ba0b-3c6276f3e96a","ip":"10.1.1.234","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:38:f0:00:01","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://889","isolationUri":"vlan://889","isSecurityGroupEnabled":false,"name":"vSwitch1,,vmwaresvs"}]},"result":false,"details":"StartCommand
failed due to Exception: java.lang.Exception\nMessage: Unsupported Disk chain length 2\n","wait":0}}]
}
    2017-03-04 20:43:40,976 DEBUG [c.c.a.t.Request] (Work-Job-Executor-4:ctx-56cda672 job-29/job-32
ctx-cf9f4cea) (logid:b0dca526) Seq 1-6353453174312927730: Received:  { Ans: , MgmtId: 7267420276525,
via: 1(10.2.2.73), Ver: v1, Flags: 10, { StartAnswer } }
    2017-03-04 20:43:40,979 INFO  [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Unable to start VM on Host[-1-Routing] due to
StartCommand failed due to Exception: java.lang.Exception
    Message: Unsupported Disk chain length 2
    
    2017-03-04 20:43:40,982 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Cleaning up resources for the vm VM[User|i-4-3-VM]
in Starting state
    2017-03-04 20:43:40,983 DEBUG [c.c.a.t.Request] (Work-Job-Executor-4:ctx-56cda672 job-29/job-32
ctx-cf9f4cea) (logid:b0dca526) Seq 1-6353453174312927733: Sending  { Cmd , MgmtId: 7267420276525,
via: 1(10.2.2.73), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"vmName":"i-4-3-VM","executeInSequence":false,"wait":0}}]
}
    2017-03-04 20:43:40,983 DEBUG [c.c.a.t.Request] (Work-Job-Executor-4:ctx-56cda672 job-29/job-32
ctx-cf9f4cea) (logid:b0dca526) Seq 1-6353453174312927733: Executing:  { Cmd , MgmtId: 7267420276525,
via: 1(10.2.2.73), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"vmName":"i-4-3-VM","executeInSequence":false,"wait":0}}]
}
    2017-03-04 20:43:40,983 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-63:ctx-6366c90c)
(logid:69a12df2) Seq 1-6353453174312927733: Executing request
    2017-03-04 20:43:40,983 INFO  [c.c.h.v.r.VmwareResource] (DirectAgent-63:ctx-6366c90c
10.2.2.73, job-29/job-32, cmd: StopCommand) (logid:b0dca526) Executing resource StopCommand:
{"isProxy":false,"checkBeforeCleanup":false,"vmName":"i-4-3-VM","executeInSequence":false,"wait":0}
    2017-03-04 20:43:40,994 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-63:ctx-6366c90c 10.2.2.73,
job-29/job-32, cmd: StopCommand) (logid:b0dca526) find VM i-4-3-VM on host
    2017-03-04 20:43:40,994 INFO  [c.c.h.v.m.HostMO] (DirectAgent-63:ctx-6366c90c 10.2.2.73,
job-29/job-32, cmd: StopCommand) (logid:b0dca526) VM i-4-3-VM not found in host cache
    2017-03-04 20:43:40,994 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-63:ctx-6366c90c 10.2.2.73,
job-29/job-32, cmd: StopCommand) (logid:b0dca526) load VM cache on host
    2017-03-04 20:43:41,043 INFO  [c.c.h.v.r.VmwareResource] (DirectAgent-63:ctx-6366c90c
10.2.2.73, job-29/job-32, cmd: StopCommand) (logid:b0dca526) VM i-4-3-VM is already in stopped
state
    2017-03-04 20:43:41,043 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-63:ctx-6366c90c)
(logid:b0dca526) Seq 1-6353453174312927733: Response Received:
    2017-03-04 20:43:41,043 DEBUG [c.c.a.t.Request] (DirectAgent-63:ctx-6366c90c) (logid:b0dca526)
Seq 1-6353453174312927733: Processing:  { Ans: , MgmtId: 7267420276525, via: 1(10.2.2.73),
Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM i-4-3-VM
is already in stopped state","wait":0}}] }
    2017-03-04 20:43:41,043 DEBUG [c.c.a.t.Request] (Work-Job-Executor-4:ctx-56cda672 job-29/job-32
ctx-cf9f4cea) (logid:b0dca526) Seq 1-6353453174312927733: Received:  { Ans: , MgmtId: 7267420276525,
via: 1(10.2.2.73), Ver: v1, Flags: 10, { StopAnswer } }
    2017-03-04 20:43:41,047 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Service SecurityGroup is not supported in the
network id=204
    2017-03-04 20:43:41,048 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Changing active number of nics for network id=204
on -1
    2017-03-04 20:43:41,053 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Asking VirtualRouter to release NicProfile[7-3-63bdc82b-0377-455e-8015-940282d98400-10.1.1.234-null
    2017-03-04 20:43:41,053 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Successfully released network resources for the
vm VM[User|i-4-3-VM]
    2017-03-04 20:43:41,053 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Successfully cleanued up resources for the vm
VM[User|i-4-3-VM] in Starting state
    2017-03-04 20:43:41,054 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Root volume is ready, need to place VM in volume's
cluster
    2017-03-04 20:43:41,054 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Vol[3|vm=3|ROOT] is READY, changing deployment
plan to use this pool's dcId: 1 , podId: 1 , and clusterId: 1
    2017-03-04 20:43:41,058 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Deploy avoids pods: [], clusters: [], hosts:
[1]
    2017-03-04 20:43:41,058 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@23d20e4e
    2017-03-04 20:43:41,058 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Trying to allocate a host and storage pools from
dc:1, pod:1,cluster:1, requested cpu: 100, requested ram: 268435456
    2017-03-04 20:43:41,058 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Is ROOT volume READY (pool already allocated)?:
Yes
    2017-03-04 20:43:41,058 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Searching resources only under specified Cluster:
1
    2017-03-04 20:43:41,063 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Checking resources in Cluster: 1 under Pod: 1
    2017-03-04 20:43:41,063 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea FirstFitRoutingAllocator) (logid:b0dca526) Looking for hosts in
dc: 1  pod:1  cluster:1
    2017-03-04 20:43:41,064 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea FirstFitRoutingAllocator) (logid:b0dca526) FirstFitAllocator has
1 hosts to check for allocation: [Host[-1-Routing]]
    2017-03-04 20:43:41,066 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea FirstFitRoutingAllocator) (logid:b0dca526) Found 1 hosts for allocation
after prioritization: [Host[-1-Routing]]
    2017-03-04 20:43:41,066 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea FirstFitRoutingAllocator) (logid:b0dca526) Looking for speed=100Mhz,
Ram=256
    2017-03-04 20:43:41,066 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea FirstFitRoutingAllocator) (logid:b0dca526) Host name: 10.2.2.73,
hostId: 1 is in avoid set, skipping this and trying other available hosts
    2017-03-04 20:43:41,066 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea FirstFitRoutingAllocator) (logid:b0dca526) Host Allocator returning
0 suitable hosts
    2017-03-04 20:43:41,066 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) No suitable hosts found
    2017-03-04 20:43:41,066 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) No suitable hosts found under this Cluster: 1
    2017-03-04 20:43:41,067 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Could not find suitable Deployment Destination
for this VM under any clusters, returning.
    2017-03-04 20:43:41,067 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Searching resources only under specified Cluster:
1
    2017-03-04 20:43:41,067 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) The specified cluster is in avoid set, returning.
    2017-03-04 20:43:41,070 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Deploy avoids pods: [], clusters: [1], hosts:
[1]
    2017-03-04 20:43:41,071 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@23d20e4e
    2017-03-04 20:43:41,071 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Trying to allocate a host and storage pools from
dc:1, pod:1,cluster:null, requested cpu: 100, requested ram: 268435456
    2017-03-04 20:43:41,071 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Is ROOT volume READY (pool already allocated)?:
No
    2017-03-04 20:43:41,071 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Searching resources only under specified Pod:
1
    2017-03-04 20:43:41,071 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Listing clusters in order of aggregate capacity,
that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
    2017-03-04 20:43:41,073 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Removing from the clusterId list these clusters
from avoid set: [1]
    2017-03-04 20:43:41,074 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) No clusters found after removing disabled clusters
and clusters in avoid list, returning.
    2017-03-04 20:43:41,083 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) 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
    2017-03-04 20:43:41,086 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Hosts's actual total CPU: 4797 and CPU after
applying overprovisioning: 9594
    2017-03-04 20:43:41,086 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Hosts's actual total RAM: 8589398016 and RAM
after applying overprovisioning: 8589398016
    2017-03-04 20:43:41,086 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) release cpu from host: 1, old used: 1600,reserved:
0, actual total: 4797, total with overprovisioning: 9594; new used: 1500,reserved:0; movedfromreserved:
false,moveToReserveredfalse
    2017-03-04 20:43:41,086 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) release mem from host: 1, old used: 2147483648,reserved:
0, total: 8589398016; new used: 1879048192,reserved:0; movedfromreserved: false,moveToReserveredfalse
    2017-03-04 20:43:41,096 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Invocation exception, caused by: com.cloud.exception.InsufficientServerCapacityException:
Unable to create a deployment for VM[User|i-4-3-VM]Scope=interface com.cloud.dc.DataCenter;
id=1
    2017-03-04 20:43:41,096 INFO  [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32 ctx-cf9f4cea) (logid:b0dca526) Rethrow exception com.cloud.exception.InsufficientServerCapacityException:
Unable to create a deployment for VM[User|i-4-3-VM]Scope=interface com.cloud.dc.DataCenter;
id=1
    2017-03-04 20:43:41,096 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32) (logid:b0dca526) Done with run of VM work job: com.cloud.vm.VmWorkStart for
VM 3, job origin: 29
    2017-03-04 20:43:41,096 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32) (logid:b0dca526) Unable to complete AsyncJobVO {id:32, userId: 2, accountId:
2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAA3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRmFjdG9ySQAJdGhyZXNob2xkeHA_QAAAAAAADHcIAAAAEAAAAAF0AApWbVBhc3N3b
 3JkdAAcck8wQUJYUUFEbk5oZG1Wa1gzQmhjM04zYjNKa3hw, cmdVersion: 0, status: IN_PROGRESS, processStatus:
0, resultCode: 0, result: null, initMsid: 7267420276525, completeMsid: null, lastUpdated:
null, lastPolled: null, created: Sat Mar 04 20:43:27 UTC 2017}, job origin:29
    com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment
for VM[User|i-4-3-VM]Scope=interface com.cloud.dc.DataCenter; id=1
    	at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:961)
    	at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4661)
    	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    	at java.lang.reflect.Method.invoke(Method.java:498)
    	at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
    	at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4822)
    	at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
    	at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
    	at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
    	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
    	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
    	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
    	at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
    	at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:502)
    	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    	at java.lang.Thread.run(Thread.java:745)
    2017-03-04 20:43:41,098 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32) (logid:b0dca526) Complete async job-32, jobStatus: FAILED, resultCode: 0, result:
rO0ABXNyADdjb20uY2xvdWQuZXhjZXB0aW9uLkluc3VmZmljaWVudFNlcnZlckNhcGFjaXR5RXhjZXB0aW9uAAAAAFZNT3ACAAFaABVhZmZpbml0eUdyb3Vwc0FwcGxpZWR4cgAxY29tLmNsb3VkLmV4Y2VwdGlvbi5JbnN1ZmZpY2llbnRDYXBhY2l0eUV4Y2VwdGlvbgAAAABWTU91AgACTAACaWR0ABBMamF2YS9sYW5nL0xvbmc7TAAFc2NvcGV0ABFMamF2YS9sYW5nL0NsYXNzO3hyACJjb20uY2xvdWQuZXhjZXB0aW9uLkNsb3VkRXhjZXB0aW9ueeiOG_HkRMcCAAJMAAtjc0Vycm9yQ29kZXQAE0xqYXZhL2xhbmcvSW50ZWdlcjtMAAZpZExpc3R0ABVMamF2YS91dGlsL0FycmF5TGlzdDt4cgATamF2YS5sYW5nLkV4Y2VwdGlvbtD9Hz4aOxzEAgAAeHIAE2phdmEubGFuZy5UaHJvd2FibGXVxjUnOXe4ywMABEwABWNhdXNldAAVTGphdmEvbGFuZy9UaHJvd2FibGU7TAANZGV0YWlsTWVzc2FnZXQAEkxqYXZhL2xhbmcvU3RyaW5nO1sACnN0YWNrVHJhY2V0AB5bTGphdmEvbGFuZy9TdGFja1RyYWNlRWxlbWVudDtMABRzdXBwcmVzc2VkRXhjZXB0aW9uc3QAEExqYXZhL3V0aWwvTGlzdDt4cHEAfgANdAAzVW5hYmxlIHRvIGNyZWF0ZSBhIGRlcGxveW1lbnQgZm9
 yIFZNW1VzZXJ8aS00LTMtVk1ddXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAVc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AApMAAhmaWxlTmFtZXEAfgAKTAAKbWV0aG9kTmFtZXEAfgAKeHAAAAPBdAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0ABBvcmNoZXN0cmF0ZVN0YXJ0c3EAfgARAAASNXEAfgATcQB-ABRxAH4AFXNxAH4AEf____50ACRzdW4ucmVmbGVjdC5OYXRpdmVNZXRob2RBY2Nlc3NvckltcGx0AB1OYXRpdmVNZXRob2RBY2Nlc3NvckltcGwuamF2YXQAB2ludm9rZTBzcQB-ABEAAAA-cQB-ABhxAH4AGXQABmludm9rZXNxAH4AEQAAACt0AChzdW4ucmVmbGVjdC5EZWxlZ2F0aW5nTWV0aG9kQWNjZXNzb3JJbXBsdAAhRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbC5qYXZhcQB-ABxzcQB-ABEAAAHydAAYamF2YS5sYW5nLnJlZmxlY3QuTWV0aG9kdAALTWV0aG9kLmphdmFxAH4AHHNxAH4AEQAAAGt0ACJjb20uY2xvdWQudm0uVm1Xb3JrSm9iSGFuZGxlclByb3h5dAAaVm1Xb3JrSm9iSGFuZGxlclByb3h5LmphdmF0AA9oYW5kbGVWbVdvcmtKb2JzcQB-ABEAABLWcQB-ABNxAH4AFHEAfgAmc3EAfgARAAAAZnQAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXNwYXRjaGVydAAYVm1Xb3Jr
 Sm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9ic3EAfgARAAACKnQAP29yZy5hcGFjaGUuY2xvdWRzdGFjay5mcmFtZXdvcmsuam9icy5pbXBsLkFzeW5jSm9iTWFuYWdlckltcGwkNXQAGEFzeW5jSm9iTWFuYWdlckltcGwuamF2YXQADHJ1bkluQ29udGV4dHNxAH4AEQAAADF0AD5vcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGUkMXQAG01hbmFnZWRDb250ZXh0UnVubmFibGUuamF2YXQAA3J1bnNxAH4AEQAAADh0AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbGxzcQB-ABEAAABndABAb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dHEAfgA2dAAPY2FsbFdpdGhDb250ZXh0c3EAfgARAAAANXEAfgA5cQB-ADZ0AA5ydW5XaXRoQ29udGV4dHNxAH4AEQAAAC50ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGVxAH4AMnEAfgAzc3EAfgARAAAB9nEAfgAtcQB-AC5xAH4AM3NxAH4AEQAAAf90AC5qYXZhLnV0aWwuY29uY3VycmVudC5FeGVjdXRvcnMkUnVubmFibGVBZGFwdGVydAAORXhlY3V0b3JzLmphdmFxAH4AN3NxAH4AEQAAAQp0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrdAAPRnV0d
 XJlVGFzay5qYXZhcQB-ADNzcQB-ABEAAAR2dAAnamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9ydAAXVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmF0AAlydW5Xb3JrZXJzcQB-ABEAAAJpdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9yJFdvcmtlcnEAfgBIcQB-ADNzcQB-ABEAAALpdAAQamF2YS5sYW5nLlRocmVhZHQAC1RocmVhZC5qYXZhcQB-ADNzcgAmamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUxpc3T8DyUxteyOEAIAAUwABGxpc3RxAH4ADHhyACxqYXZhLnV0aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlQ29sbGVjdGlvbhlCAIDLXvceAgABTAABY3QAFkxqYXZhL3V0aWwvQ29sbGVjdGlvbjt4cHNyABNqYXZhLnV0aWwuQXJyYXlMaXN0eIHSHZnHYZ0DAAFJAARzaXpleHAAAAAAdwQAAAAAeHEAfgBUeHNyABFqYXZhLmxhbmcuSW50ZWdlchLioKT3gYc4AgABSQAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAABDvc3EAfgBTAAAAAHcEAAAAAHhzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHEAfgBWAAAAAAAAAAF2cgAXY29tLmNsb3VkLmRjLkRhdGFDZW50ZXKy8Qrrp-d4vgIAAHhwAA
    2017-03-04 20:43:41,098 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32) (logid:b0dca526) Publish async job-32 complete on message bus
    2017-03-04 20:43:41,098 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32) (logid:b0dca526) Wake up jobs related to job-32
    2017-03-04 20:43:41,098 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32) (logid:b0dca526) Update db status for job-32
    2017-03-04 20:43:41,099 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32) (logid:b0dca526) Wake up jobs joined with job-32 and disjoin all subjobs created
from job- 32
    2017-03-04 20:43:41,105 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32) (logid:b0dca526) Done executing com.cloud.vm.VmWorkStart for job-32
    2017-03-04 20:43:41,107 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-4:ctx-56cda672
job-29/job-32) (logid:b0dca526) Remove job-32 from job monitoring
    2017-03-04 20:43:41,113 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-23:ctx-0c7ca79a
job-29 ctx-f34539ef) (logid:b0dca526) Destroying vm VM[User|i-4-3-VM] as it failed to create
on Host with Id:null
    2017-03-04 20:43:41,120 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-23:ctx-0c7ca79a
job-29 ctx-f34539ef) (logid:b0dca526) 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
    2017-03-04 20:43:41,151 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-23:ctx-0c7ca79a
job-29 ctx-f34539ef) (logid:b0dca526) Access granted to Acct[eb82ac50-0109-11e7-af92-069c1401072d-admin]
to Domain:1/ by AffinityGroupAccessChecker
    2017-03-04 20:43:41,160 WARN  [o.a.c.alerts] (API-Job-Executor-23:ctx-0c7ca79a job-29
ctx-f34539ef) (logid:b0dca526)  alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId::
null // message:: Failed to deploy Vm with Id: 3, on Host with Id: null
    2017-03-04 20:43:41,180 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-23:ctx-0c7ca79a
job-29) (logid:b0dca526) Unexpected exception while executing org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin
    com.cloud.utils.exception.CloudRuntimeException: Unable to start a VM due to insufficient
capacity
    	at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:623)
    	at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:242)
    	at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:212)
    	at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4097)
    	at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3695)
    	at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3683)
    	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    	at java.lang.reflect.Method.invoke(Method.java:498)
    	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    	at org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
    	at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
    	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
    	at com.sun.proxy.$Proxy205.startVirtualMachine(Unknown Source)
    	at org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin.execute(DeployVMCmdByAdmin.java:50)
    	at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:150)
    	at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
    	at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
    	at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
    	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
    	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
    	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
    	at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
    	at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:502)
    	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    	at java.lang.Thread.run(Thread.java:745)
    Caused by: com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-4-3-VM]Scope=interface com.cloud.dc.DataCenter; id=1
    	at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:961)
    	at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4661)
    	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    	... 18 more
    2017-03-04 20:43:41,182 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-23:ctx-0c7ca79a
job-29) (logid:b0dca526) Complete async job-29, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable
to start a VM due to insufficient capacity"}
    ```


---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---

Mime
View raw message