Hello,
Could someone give me a light.
I registered an ISO at ACS all right download 100%!
When trying to create an instance appear from this ISO, I am having some
problems.
Here is information from the servers:
Server KVM:
free -h
total used free
Mem: 7,6G 1,6G 5,5G
Swap: 7,9G 0B 7,9G
System Capacity
Memory - 1.50 GB / 6.63 GB
CPU - 1.00 GHz / 12.40 GHz
Storage - 8.36 GB / 49.98 GB
Public IP Addresses - 3 / 10
Management IP Addresses - 2 / 21
Secondary Storage - 9.07 GB / 59.76 GB
Local Storage - 192.50 KB / 99.95 GB
GPU - 0%
of CPU Cores - 2 / 4 50%
LOGS ACS:
Status
Unable to create a deployment for VM[User|i-2-88-VM]
2020-03-16 15:22:02,910 DEBUG [c.c.a.ApiServlet] (qtp504527234-12:ctx-d2942ec6)
(logid:5742ceb6) ===START=== 172.26.0.190 -- GET
command=deployVirtualMachine&response=json&zoneid=f525ca16-891e-4749-b147-d426ecfab483&podid=673181c2-43fb-45e2-91b0-7496f2975a7b&clusterid=81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83&hostid=6d169723-2440-46a5-a815-67580656dd6d&templateid=eb47e5c4-c18e-4706-8f54-518dd5eee6e0&hypervisor=KVM&serviceofferingid=05d73569-bd80-48d7-b067-2dfc908be3a2&diskofferingid=e1efe3de-bda9-4766-9ad0-29ac76a57dc5&iptonetworklist%5B0%5D.networkid=2cc628f1-54e8-4a9b-974a-474b887a7910&displayname=vmcenots7teste&name=vmcenots7teste&_=1584381583983
2020-03-16 15:22:02,916 DEBUG [c.c.a.ApiServer] (qtp504527234-12:ctx-d2942ec6
ctx-2f01ad38) (logid:5742ceb6) CIDRs from which account
'Acct[e8c8861d-5f9c-11ea-bb9d-080027a1c01e-admin]' is allowed to perform API
calls: 0.0.0.0/0,::/0
2020-03-16 15:22:02,986 DEBUG [c.c.u.AccountManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Access granted to
Acct[e8c8861d-5f9c-11ea-bb9d-080027a1c01e-admin] to
org.apache.cloudstack.quota.vo.ServiceOfferingVO$$EnhancerByCGLIB$$3bcf647@5bc9c6ce
by AffinityGroupAccessChecker
2020-03-16 15:22:02,991 DEBUG [c.c.u.AccountManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Access granted to
Acct[e8c8861d-5f9c-11ea-bb9d-080027a1c01e-admin] to
com.cloud.storage.DiskOfferingVO$$EnhancerByCGLIB$$ac86733a@41011f77 by
AffinityGroupAccessChecker
2020-03-16 15:22:03,007 DEBUG [c.c.n.NetworkModelImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,092 DEBUG [c.c.v.UserVmManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocating in the
DB for vm
2020-03-16 15:22:03,119 DEBUG [c.c.v.VirtualMachineManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocating entries
for VM: VM[User|i-2-88-VM]
2020-03-16 15:22:03,120 DEBUG [c.c.v.VirtualMachineManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocating nics
for VM[User|i-2-88-VM]
2020-03-16 15:22:03,121 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocating nic for
vm VM[User|i-2-88-VM] in network Ntwk[204|Guest|8] with requested profile
NicProfile[0-0-null-null-null
2020-03-16 15:22:03,135 DEBUG [c.c.n.NetworkModelImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,137 DEBUG [c.c.v.VirtualMachineManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocating disks
for VM[User|i-2-88-VM]
2020-03-16 15:22:03,140 DEBUG [c.c.r.ResourceLimitManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Updating resource
Type = volume count for Account = 2 Operation = increasing Amount = 1
2020-03-16 15:22:03,143 DEBUG [c.c.r.ResourceLimitManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Updating resource
Type = primary_storage count for Account = 2 Operation = increasing Amount =
5368709120
2020-03-16 15:22:03,145 DEBUG [c.c.v.VirtualMachineManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocation
completed for VM: VM[User|i-2-88-VM]
2020-03-16 15:22:03,145 DEBUG [c.c.v.UserVmManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Successfully
allocated DB entry for VM[User|i-2-88-VM]
2020-03-16 15:22:03,146 DEBUG [c.c.r.ResourceLimitManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Updating resource
Type = user_vm count for Account = 2 Operation = increasing Amount = 1
2020-03-16 15:22:03,148 DEBUG [c.c.r.ResourceLimitManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Updating resource
Type = cpu count for Account = 2 Operation = increasing Amount = 1
2020-03-16 15:22:03,151 DEBUG [c.c.r.ResourceLimitManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Updating resource
Type = memory count for Account = 2 Operation = increasing Amount = 512
2020-03-16 15:22:03,234 DEBUG [c.c.n.NetworkModelImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,237 DEBUG [c.c.n.NetworkModelImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,249 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:da732267) Add job-334 into job
monitoring
2020-03-16 15:22:03,253 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) submit async
job-334, details: AsyncJobVO {id:334, userId: 2, accountId: 2, instanceType:
VirtualMachine, instanceId: 88, cmd:
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin, cmdInfo:
{"iptonetworklist[0].networkid":"2cc628f1-54e8-4a9b-974a-474b887a7910","hostid":"6d169723-2440-46a5-a815-67580656dd6d","httpmethod":"GET","clusterid":"81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83","templateid":"eb47e5c4-c18e-4706-8f54-518dd5eee6e0","ctxAccountId":"2","uuid":"e360583b-48cc-4690-a730-dbc8993e4f04","cmdEventType":"VM.CREATE","diskofferingid":"e1efe3de-bda9-4766-9ad0-29ac76a57dc5","serviceofferingid":"05d73569-bd80-48d7-b067-2dfc908be3a2","response":"json","ctxUserId":"2","hypervisor":"KVM","displayname":"vmcenots7teste","name":"vmcenots7teste","zoneid":"f525ca16-891e-4749-b147-d426ecfab483","ctxStartEventId":"276","id":"88","ctxDetails":"{\"interface
com.cloud.dc.Pod\":\"673181c2-43fb-45e2-91b0-7496f2975a7b\",\"interface
com.cloud.org.Cluster\":\"81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83\",\"interface
com.cloud.offering.ServiceOffering\":\"05d73569-bd80-48d7-b067-2dfc908be3a2\",\"interface
com.cloud.host.Host\":\"6d169723-2440-46a5-a815-67580656dd6d\",\"interface
com.cloud.template.VirtualMachineTemplate\":\"eb47e5c4-c18e-4706-8f54-518dd5eee6e0\",\"interface
com.cloud.dc.DataCenter\":\"f525ca16-891e-4749-b147-d426ecfab483\",\"interface
com.cloud.offering.DiskOffering\":\"e1efe3de-bda9-4766-9ad0-29ac76a57dc5\",\"interface
com.cloud.vm.VirtualMachine\":\"e360583b-48cc-4690-a730-dbc8993e4f04\"}","podid":"673181c2-43fb-45e2-91b0-7496f2975a7b","_":"1584381583983"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 8796757934110, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null, removed: null}
2020-03-16 15:22:03,254 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Executing AsyncJobVO
{id:334, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 88,
cmd: org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin, cmdInfo:
{"iptonetworklist[0].networkid":"2cc628f1-54e8-4a9b-974a-474b887a7910","hostid":"6d169723-2440-46a5-a815-67580656dd6d","httpmethod":"GET","clusterid":"81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83","templateid":"eb47e5c4-c18e-4706-8f54-518dd5eee6e0","ctxAccountId":"2","uuid":"e360583b-48cc-4690-a730-dbc8993e4f04","cmdEventType":"VM.CREATE","diskofferingid":"e1efe3de-bda9-4766-9ad0-29ac76a57dc5","serviceofferingid":"05d73569-bd80-48d7-b067-2dfc908be3a2","response":"json","ctxUserId":"2","hypervisor":"KVM","displayname":"vmcenots7teste","name":"vmcenots7teste","zoneid":"f525ca16-891e-4749-b147-d426ecfab483","ctxStartEventId":"276","id":"88","ctxDetails":"{\"interface
com.cloud.dc.Pod\":\"673181c2-43fb-45e2-91b0-7496f2975a7b\",\"interface
com.cloud.org.Cluster\":\"81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83\",\"interface
com.cloud.offering.ServiceOffering\":\"05d73569-bd80-48d7-b067-2dfc908be3a2\",\"interface
com.cloud.host.Host\":\"6d169723-2440-46a5-a815-67580656dd6d\",\"interface
com.cloud.template.VirtualMachineTemplate\":\"eb47e5c4-c18e-4706-8f54-518dd5eee6e0\",\"interface
com.cloud.dc.DataCenter\":\"f525ca16-891e-4749-b147-d426ecfab483\",\"interface
com.cloud.offering.DiskOffering\":\"e1efe3de-bda9-4766-9ad0-29ac76a57dc5\",\"interface
com.cloud.vm.VirtualMachine\":\"e360583b-48cc-4690-a730-dbc8993e4f04\"}","podid":"673181c2-43fb-45e2-91b0-7496f2975a7b","_":"1584381583983"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 8796757934110, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null, removed: null}
2020-03-16 15:22:03,255 DEBUG [c.c.a.ApiServlet] (qtp504527234-12:ctx-d2942ec6
ctx-2f01ad38) (logid:5742ceb6) ===END=== 172.26.0.190 -- GET
command=deployVirtualMachine&response=json&zoneid=f525ca16-891e-4749-b147-d426ecfab483&podid=673181c2-43fb-45e2-91b0-7496f2975a7b&clusterid=81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83&hostid=6d169723-2440-46a5-a815-67580656dd6d&templateid=eb47e5c4-c18e-4706-8f54-518dd5eee6e0&hypervisor=KVM&serviceofferingid=05d73569-bd80-48d7-b067-2dfc908be3a2&diskofferingid=e1efe3de-bda9-4766-9ad0-29ac76a57dc5&iptonetworklist%5B0%5D.networkid=2cc628f1-54e8-4a9b-974a-474b887a7910&displayname=vmcenots7teste&name=vmcenots7teste&_=1584381583983
2020-03-16 15:22:03,473 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,479 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,482 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Destination Host to deploy the VM is specified, specifying a deployment plan to
deploy the VM
2020-03-16 15:22:03,567 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
DeploymentPlanner allocation algorithm: null
2020-03-16 15:22:03,567 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Trying
to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu:
500, requested ram: 536870912
2020-03-16 15:22:03,567 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Is ROOT
volume READY (pool already allocated)?: No
2020-03-16 15:22:03,567 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
DeploymentPlan has host_id specified, choosing this host and making no checks
on this host: 1
2020-03-16 15:22:03,574 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Looking
for suitable pools for this host under zone: 1, pod: 1, cluster: 1
2020-03-16 15:22:03,582 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Checking suitable pools for volume (Id, Type): (89,ROOT)
2020-03-16 15:22:03,582 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) We need
to allocate new storagepool for this volume
2020-03-16 15:22:03,587 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Calling
StoragePoolAllocators to find suitable pools
2020-03-16 15:22:03,596 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
LocalStoragePoolAllocator trying to find storage pool to fit the vm
2020-03-16 15:22:03,596 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
ClusterScopeStoragePoolAllocator looking for storage pool
2020-03-16 15:22:03,596 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Looking
for pools in dc: 1 pod:1 cluster:1. Disabled pools will be ignored.
2020-03-16 15:22:03,598 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Found
pools matching tags: []
2020-03-16 15:22:03,601 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) No
storage pools available for shared volume allocation, returning
2020-03-16 15:22:03,601 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
ZoneWideStoragePoolAllocator to find storage pool
2020-03-16 15:22:03,633 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) No
suitable pools found for volume: Vol[89|vm=88|ROOT] under cluster: 1
2020-03-16 15:22:03,633 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) No
suitable pools found
2020-03-16 15:22:03,633 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Cannot
deploy to specified host, returning.
2020-03-16 15:22:03,646 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Destroying vm VM[User|i-2-88-VM] as it failed to create on Host with Id:1
2020-03-16 15:22:03,680 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) 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
2020-03-16 15:22:03,713 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Updating resource Type = volume count for Account = 2 Operation = decreasing
Amount = 1
2020-03-16 15:22:03,719 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Updating resource Type = primary_storage count for Account = 2 Operation =
decreasing Amount = 5368709120
2020-03-16 15:22:03,727 WARN [c.c.a.AlertManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
AlertType:: 8 | dataCenterId:: 1 | podId:: null | clusterId:: null | message::
Failed to deploy Vm with Id: 88, on Host with Id: 1
2020-03-16 15:22:03,732 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Updating resource Type = user_vm count for Account = 2 Operation = decreasing
Amount = 1
2020-03-16 15:22:03,738 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Updating resource Type = cpu count for Account = 2 Operation = decreasing
Amount = 1
2020-03-16 15:22:03,744 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Updating resource Type = memory count for Account = 2 Operation = decreasing
Amount = 512
2020-03-16 15:22:03,754 INFO [o.a.c.a.c.a.v.DeployVMCmdByAdmin]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-88-VM]Scope=interface com.cloud.dc.DataCenter; id=1
2020-03-16 15:22:03,755 INFO [o.a.c.a.c.a.v.DeployVMCmdByAdmin]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Unable
to create a deployment for VM[User|i-2-88-VM]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-88-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:215)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:200)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4683)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4232)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4222)
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:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy190.startVirtualMachine(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin.execute(DeployVMCmdByAdmin.java:67)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:156)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:583)
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:531)
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:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2020-03-16 15:22:03,758 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Complete async
job-334, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":533,"errortext":"Unable
to create a deployment for VM[User|i-2-88-VM]"}
2020-03-16 15:22:03,763 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Publish async
job-334 complete on message bus
2020-03-16 15:22:03,763 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Wake up jobs related
to job-334
2020-03-16 15:22:03,763 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Update db status for
job-334
2020-03-16 15:22:03,764 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Wake up jobs joined
with job-334 and disjoin all subjobs created from job- 334
2020-03-16 15:22:03,770 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Done executing
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin for job-334
2020-03-16 15:22:03,771 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Remove job-334 from
job monitoring
2020-03-16 15:22:04,307 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-7619aa30) (logid:40e03141) Zone 1 is read2020-03-16
15:22:02,910 DEBUG [c.c.a.ApiServlet] (qtp504527234-12:ctx-d2942ec6)
(logid:5742ceb6) ===START=== 172.26.0.190 -- GET
command=deployVirtualMachine&response=json&zoneid=f525ca16-891e-4749-b147-d426ecfab483&podid=673181c2-43fb-45e2-91b0-7496f2975a7b&clusterid=81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83&hostid=6d169723-2440-46a5-a815-67580656dd6d&templateid=eb47e5c4-c18e-4706-8f54-518dd5eee6e0&hypervisor=KVM&serviceofferingid=05d73569-bd80-48d7-b067-2dfc908be3a2&diskofferingid=e1efe3de-bda9-4766-9ad0-29ac76a57dc5&iptonetworklist%5B0%5D.networkid=2cc628f1-54e8-4a9b-974a-474b887a7910&displayname=vmcenots7teste&name=vmcenots7teste&_=1584381583983
2020-03-16 15:22:02,916 DEBUG [c.c.a.ApiServer] (qtp504527234-12:ctx-d2942ec6
ctx-2f01ad38) (logid:5742ceb6) CIDRs from which account
'Acct[e8c8861d-5f9c-11ea-bb9d-080027a1c01e-admin]' is allowed to perform API
calls: 0.0.0.0/0,::/0
2020-03-16 15:22:02,986 DEBUG [c.c.u.AccountManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Access granted to
Acct[e8c8861d-5f9c-11ea-bb9d-080027a1c01e-admin] to
org.apache.cloudstack.quota.vo.ServiceOfferingVO$$EnhancerByCGLIB$$3bcf647@5bc9c6ce
by AffinityGroupAccessChecker
2020-03-16 15:22:02,991 DEBUG [c.c.u.AccountManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Access granted to
Acct[e8c8861d-5f9c-11ea-bb9d-080027a1c01e-admin] to
com.cloud.storage.DiskOfferingVO$$EnhancerByCGLIB$$ac86733a@41011f77 by
AffinityGroupAccessChecker
2020-03-16 15:22:03,007 DEBUG [c.c.n.NetworkModelImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,092 DEBUG [c.c.v.UserVmManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocating in the
DB for vm
2020-03-16 15:22:03,119 DEBUG [c.c.v.VirtualMachineManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocating entries
for VM: VM[User|i-2-88-VM]
2020-03-16 15:22:03,120 DEBUG [c.c.v.VirtualMachineManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocating nics
for VM[User|i-2-88-VM]
2020-03-16 15:22:03,121 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocating nic for
vm VM[User|i-2-88-VM] in network Ntwk[204|Guest|8] with requested profile
NicProfile[0-0-null-null-null
2020-03-16 15:22:03,135 DEBUG [c.c.n.NetworkModelImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,137 DEBUG [c.c.v.VirtualMachineManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocating disks
for VM[User|i-2-88-VM]
2020-03-16 15:22:03,140 DEBUG [c.c.r.ResourceLimitManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Updating resource
Type = volume count for Account = 2 Operation = increasing Amount = 1
2020-03-16 15:22:03,143 DEBUG [c.c.r.ResourceLimitManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Updating resource
Type = primary_storage count for Account = 2 Operation = increasing Amount =
5368709120
2020-03-16 15:22:03,145 DEBUG [c.c.v.VirtualMachineManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Allocation
completed for VM: VM[User|i-2-88-VM]
2020-03-16 15:22:03,145 DEBUG [c.c.v.UserVmManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Successfully
allocated DB entry for VM[User|i-2-88-VM]
2020-03-16 15:22:03,146 DEBUG [c.c.r.ResourceLimitManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Updating resource
Type = user_vm count for Account = 2 Operation = increasing Amount = 1
2020-03-16 15:22:03,148 DEBUG [c.c.r.ResourceLimitManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Updating resource
Type = cpu count for Account = 2 Operation = increasing Amount = 1
2020-03-16 15:22:03,151 DEBUG [c.c.r.ResourceLimitManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Updating resource
Type = memory count for Account = 2 Operation = increasing Amount = 512
2020-03-16 15:22:03,234 DEBUG [c.c.n.NetworkModelImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,237 DEBUG [c.c.n.NetworkModelImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,249 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:da732267) Add job-334 into job
monitoring
2020-03-16 15:22:03,253 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp504527234-12:ctx-d2942ec6 ctx-2f01ad38) (logid:5742ceb6) submit async
job-334, details: AsyncJobVO {id:334, userId: 2, accountId: 2, instanceType:
VirtualMachine, instanceId: 88, cmd:
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin, cmdInfo:
{"iptonetworklist[0].networkid":"2cc628f1-54e8-4a9b-974a-474b887a7910","hostid":"6d169723-2440-46a5-a815-67580656dd6d","httpmethod":"GET","clusterid":"81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83","templateid":"eb47e5c4-c18e-4706-8f54-518dd5eee6e0","ctxAccountId":"2","uuid":"e360583b-48cc-4690-a730-dbc8993e4f04","cmdEventType":"VM.CREATE","diskofferingid":"e1efe3de-bda9-4766-9ad0-29ac76a57dc5","serviceofferingid":"05d73569-bd80-48d7-b067-2dfc908be3a2","response":"json","ctxUserId":"2","hypervisor":"KVM","displayname":"vmcenots7teste","name":"vmcenots7teste","zoneid":"f525ca16-891e-4749-b147-d426ecfab483","ctxStartEventId":"276","id":"88","ctxDetails":"{\"interface
com.cloud.dc.Pod\":\"673181c2-43fb-45e2-91b0-7496f2975a7b\",\"interface
com.cloud.org.Cluster\":\"81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83\",\"interface
com.cloud.offering.ServiceOffering\":\"05d73569-bd80-48d7-b067-2dfc908be3a2\",\"interface
com.cloud.host.Host\":\"6d169723-2440-46a5-a815-67580656dd6d\",\"interface
com.cloud.template.VirtualMachineTemplate\":\"eb47e5c4-c18e-4706-8f54-518dd5eee6e0\",\"interface
com.cloud.dc.DataCenter\":\"f525ca16-891e-4749-b147-d426ecfab483\",\"interface
com.cloud.offering.DiskOffering\":\"e1efe3de-bda9-4766-9ad0-29ac76a57dc5\",\"interface
com.cloud.vm.VirtualMachine\":\"e360583b-48cc-4690-a730-dbc8993e4f04\"}","podid":"673181c2-43fb-45e2-91b0-7496f2975a7b","_":"1584381583983"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 8796757934110, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null, removed: null}
2020-03-16 15:22:03,254 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Executing AsyncJobVO
{id:334, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 88,
cmd: org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin, cmdInfo:
{"iptonetworklist[0].networkid":"2cc628f1-54e8-4a9b-974a-474b887a7910","hostid":"6d169723-2440-46a5-a815-67580656dd6d","httpmethod":"GET","clusterid":"81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83","templateid":"eb47e5c4-c18e-4706-8f54-518dd5eee6e0","ctxAccountId":"2","uuid":"e360583b-48cc-4690-a730-dbc8993e4f04","cmdEventType":"VM.CREATE","diskofferingid":"e1efe3de-bda9-4766-9ad0-29ac76a57dc5","serviceofferingid":"05d73569-bd80-48d7-b067-2dfc908be3a2","response":"json","ctxUserId":"2","hypervisor":"KVM","displayname":"vmcenots7teste","name":"vmcenots7teste","zoneid":"f525ca16-891e-4749-b147-d426ecfab483","ctxStartEventId":"276","id":"88","ctxDetails":"{\"interface
com.cloud.dc.Pod\":\"673181c2-43fb-45e2-91b0-7496f2975a7b\",\"interface
com.cloud.org.Cluster\":\"81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83\",\"interface
com.cloud.offering.ServiceOffering\":\"05d73569-bd80-48d7-b067-2dfc908be3a2\",\"interface
com.cloud.host.Host\":\"6d169723-2440-46a5-a815-67580656dd6d\",\"interface
com.cloud.template.VirtualMachineTemplate\":\"eb47e5c4-c18e-4706-8f54-518dd5eee6e0\",\"interface
com.cloud.dc.DataCenter\":\"f525ca16-891e-4749-b147-d426ecfab483\",\"interface
com.cloud.offering.DiskOffering\":\"e1efe3de-bda9-4766-9ad0-29ac76a57dc5\",\"interface
com.cloud.vm.VirtualMachine\":\"e360583b-48cc-4690-a730-dbc8993e4f04\"}","podid":"673181c2-43fb-45e2-91b0-7496f2975a7b","_":"1584381583983"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 8796757934110, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null, removed: null}
2020-03-16 15:22:03,255 DEBUG [c.c.a.ApiServlet] (qtp504527234-12:ctx-d2942ec6
ctx-2f01ad38) (logid:5742ceb6) ===END=== 172.26.0.190 -- GET
command=deployVirtualMachine&response=json&zoneid=f525ca16-891e-4749-b147-d426ecfab483&podid=673181c2-43fb-45e2-91b0-7496f2975a7b&clusterid=81cb2d64-d39c-40c5-a3ad-8b8e9fce4f83&hostid=6d169723-2440-46a5-a815-67580656dd6d&templateid=eb47e5c4-c18e-4706-8f54-518dd5eee6e0&hypervisor=KVM&serviceofferingid=05d73569-bd80-48d7-b067-2dfc908be3a2&diskofferingid=e1efe3de-bda9-4766-9ad0-29ac76a57dc5&iptonetworklist%5B0%5D.networkid=2cc628f1-54e8-4a9b-974a-474b887a7910&displayname=vmcenots7teste&name=vmcenots7teste&_=1584381583983
2020-03-16 15:22:03,473 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,479 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Service
SecurityGroup is not supported in the network id=204
2020-03-16 15:22:03,482 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Destination Host to deploy the VM is specified, specifying a deployment plan to
deploy the VM
2020-03-16 15:22:03,567 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
DeploymentPlanner allocation algorithm: null
2020-03-16 15:22:03,567 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Trying
to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu:
500, requested ram: 536870912
2020-03-16 15:22:03,567 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Is ROOT
volume READY (pool already allocated)?: No
2020-03-16 15:22:03,567 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
DeploymentPlan has host_id specified, choosing this host and making no checks
on this host: 1
2020-03-16 15:22:03,574 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Looking
for suitable pools for this host under zone: 1, pod: 1, cluster: 1
2020-03-16 15:22:03,582 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Checking suitable pools for volume (Id, Type): (89,ROOT)
2020-03-16 15:22:03,582 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) We need
to allocate new storagepool for this volume
2020-03-16 15:22:03,587 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Calling
StoragePoolAllocators to find suitable pools
2020-03-16 15:22:03,596 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
LocalStoragePoolAllocator trying to find storage pool to fit the vm
2020-03-16 15:22:03,596 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
ClusterScopeStoragePoolAllocator looking for storage pool
2020-03-16 15:22:03,596 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Looking
for pools in dc: 1 pod:1 cluster:1. Disabled pools will be ignored.
2020-03-16 15:22:03,598 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Found
pools matching tags: []
2020-03-16 15:22:03,601 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) No
storage pools available for shared volume allocation, returning
2020-03-16 15:22:03,601 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
ZoneWideStoragePoolAllocator to find storage pool
2020-03-16 15:22:03,633 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) No
suitable pools found for volume: Vol[89|vm=88|ROOT] under cluster: 1
2020-03-16 15:22:03,633 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) No
suitable pools found
2020-03-16 15:22:03,633 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Cannot
deploy to specified host, returning.
2020-03-16 15:22:03,646 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Destroying vm VM[User|i-2-88-VM] as it failed to create on Host with Id:1
2020-03-16 15:22:03,680 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) 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
2020-03-16 15:22:03,713 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Updating resource Type = volume count for Account = 2 Operation = decreasing
Amount = 1
2020-03-16 15:22:03,719 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Updating resource Type = primary_storage count for Account = 2 Operation =
decreasing Amount = 5368709120
2020-03-16 15:22:03,727 WARN [c.c.a.AlertManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
AlertType:: 8 | dataCenterId:: 1 | podId:: null | clusterId:: null | message::
Failed to deploy Vm with Id: 88, on Host with Id: 1
2020-03-16 15:22:03,732 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Updating resource Type = user_vm count for Account = 2 Operation = decreasing
Amount = 1
2020-03-16 15:22:03,738 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Updating resource Type = cpu count for Account = 2 Operation = decreasing
Amount = 1
2020-03-16 15:22:03,744 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
Updating resource Type = memory count for Account = 2 Operation = decreasing
Amount = 512
2020-03-16 15:22:03,754 INFO [o.a.c.a.c.a.v.DeployVMCmdByAdmin]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3)
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-88-VM]Scope=interface com.cloud.dc.DataCenter; id=1
2020-03-16 15:22:03,755 INFO [o.a.c.a.c.a.v.DeployVMCmdByAdmin]
(API-Job-Executor-4:ctx-fced2864 job-334 ctx-05435593) (logid:2fac8aa3) Unable
to create a deployment for VM[User|i-2-88-VM]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-88-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:215)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:200)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4683)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4232)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4222)
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:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy190.startVirtualMachine(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin.execute(DeployVMCmdByAdmin.java:67)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:156)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:583)
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:531)
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:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2020-03-16 15:22:03,758 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Complete async
job-334, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":533,"errortext":"Unable
to create a deployment for VM[User|i-2-88-VM]"}
2020-03-16 15:22:03,763 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Publish async
job-334 complete on message bus
2020-03-16 15:22:03,763 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Wake up jobs related
to job-334
2020-03-16 15:22:03,763 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Update db status for
job-334
2020-03-16 15:22:03,764 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Wake up jobs joined
with job-334 and disjoin all subjobs created from job- 334
2020-03-16 15:22:03,770 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Done executing
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin for job-334
2020-03-16 15:22:03,771 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-4:ctx-fced2864 job-334) (logid:2fac8aa3) Remove job-334 from
job monitoring
2020-03-16 15:22:04,307 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-7619aa30) (logid:40e03141) Zone 1 is ready to launch
console proxy
2020-03-16 15:22:04,678 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-46e91e19) (logid:a748b819) Zone 1 is ready to launch
secondary storage VM
2020-03-16 15:22:05,320 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Resetting hosts suitable for reconnect
2020-03-16 15:22:05,323 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Completed resetting hosts suitable for
reconnect
2020-03-16 15:22:05,323 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Acquiring hosts for clusters already owned
by this management server
2020-03-16 15:22:05,325 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Completed acquiring hosts for clusters
already owned by this management server
2020-03-16 15:22:05,325 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Acquiring hosts for clusters not owned by
any management server
2020-03-16 15:22:05,325 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Completed acquiring hosts for clusters not
owned by any management server
2020-03-16 15:22:05,613 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-14:null) (logid:) SeqA 4-42: Processing Seq 4-42: { Cmd
, MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":87,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2020-03-16 15:22:05,623 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-14:null) (logid:) SeqA 4-42: Sending Seq 4-42: { Ans: ,
MgmtId: 8796757934110, via: 4, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2020-03-16 15:22:06,274 DEBUG [c.c.a.ApiServlet] (qtp504527234-14:ctx-9a48da8b)
(logid:fe9d2b1e) ===START=== 172.26.0.190 -- GET
command=queryAsyncJobResult&jobId=2fac8aa3-653b-4d69-8502-9b2da0fc4206&response=json&_=1584381583984
2020-03-16 15:22:06,283 DEBUG [c.c.a.ApiServer] (qtp504527234-14:ctx-9a48da8b
ctx-8c468fd0) (logid:fe9d2b1e) CIDRs from which account
'Acct[e8c8861d-5f9c-11ea-bb9d-080027a1c01e-admin]' is allowed to perform API
calls: 0.0.0.0/0,::/0
2020-03-16 15:22:06,294 DEBUG [c.c.a.ApiServlet] (qtp504527234-14:ctx-9a48da8b
ctx-8c468fd0) (logid:fe9d2b1e) ===END=== 172.26.0.190 -- GET
command=queryAsyncJobResult&jobId=2fac8aa3-653b-4d69-8502-9b2da0fc4206&response=json&_=1584381583984
2020-03-16 15:22:06,298 DEBUG [c.c.a.ApiServlet] (qtp504527234-12:ctx-6de5d048)
(logid:ca0fdf73) ===START=== 172.26.0.190 -- GET
command=listVirtualMachines&id=e360583b-48cc-4690-a730-dbc8993e4f04&response=json&_=1584381583985
2020-03-16 15:22:06,304 DEBUG [c.c.a.ApiServer] (qtp504527234-12:ctx-6de5d048
ctx-2a557c0b) (logid:ca0fdf73) CIDRs from which account
'Acct[e8c8861d-5f9c-11ea-bb9d-080027a1c01e-admin]' is allowed to perform API
calls: 0.0.0.0/0,::/0
2020-03-16 15:22:06,348 DEBUG [c.c.a.ApiServlet] (qtp504527234-12:ctx-6de5d048
ctx-2a557c0b) (logid:ca0fdf73) ===END=== 172.26.0.190 -- GET
command=listVirtualMachines&id=e360583b-48cc-4690-a730-dbc8993e4f04&response=json&_=1584381583985
2020-03-16 15:22:08,504 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-5993cfec) (logid:91d56cda) Begin cleanup expired
async-jobs
2020-03-16 15:22:08,509 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-5993cfec) (logid:91d56cda) End cleanup expired
async-jobs
2020-03-16 15:22:10,090 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru]
(Timer-8:ctx-c995a317) (logid:d0bfed48) getCommandHostDelegation: class
org.apache.cloudstack.storage.command.DownloadProgressCommand
2020-03-16 15:22:10,093 DEBUG [c.c.h.XenServerGuru] (Timer-8:ctx-c995a317)
(logid:d0bfed48) We are returning the default host to execute commands because
the command is not of Copy type.
2020-03-16 15:22:10,093 DEBUG [o.a.c.s.RemoteHostEndPoint]
(Timer-8:ctx-c995a317) (logid:d0bfed48) Sending command
org.apache.cloudstack.storage.command.DownloadProgressCommand to host: 3
2020-03-16 15:22:10,096 DEBUG [c.c.a.t.Request] (Timer-8:ctx-c995a317)
(logid:d0bfed48) Seq 3-7278661422760853572: Sending { Cmd , MgmtId:
8796757934110, via: 3(s-73-VM), Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.DownloadProgressCommand":{"jobId":"4252f6a6-a0c5-491b-b597-fa1987a9b9b1","request":"GET_STATUS","hvm":false,"description":"SystemVM
Template
(KVM)","checksum":"15ec268d0939a8fa0be1bc79f397a167","maxDownloadSizeInBytes":53687091200,"id":3,"resourceType":"TEMPLATE","installPath":"template/tmpl/1/3","_store":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://172.26.0.222/export/secondary","_role":"Image"}},"url":"http://download.cloudstack.org/systemvm/4.11/systemvmtemplate-4.11.3-kvm.qcow2.bz2","format":"QCOW2","accountId":1,"name":"routing-3","secUrl":"nfs://172.26.0.222/export/secondary","wait":0}}]
}
2020-03-16 15:22:10,146 DEBUG [c.c.a.t.Request] (AgentManager-Handler-15:null)
(logid:) Seq 3-7278661422760853572: Processing: { Ans: , MgmtId:
8796757934110, via: 3, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.storage.DownloadAnswer":{"jobId":"4252f6a6-a0c5-491b-b597-fa1987a9b9b1","downloadPct":74,"errorString":"
","downloadStatus":"DOWNLOAD_IN_PROGRESS","downloadPath":"/mnt/SecStorage/3bacb604-b035-378f-8f59-3a646c9dc0b4/template/tmpl/1/3/dnld5913098205028932528tmp_","installPath":"template/tmpl/1/3","templateSize":0,"templatePhySicalSize":0,"checkSum":"15ec268d0939a8fa0be1bc79f397a167","result":true,"details":"
","wait":0}}] }
2020-03-16 15:22:10,147 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl]
(RemoteHostEndPoint-3:ctx-46787815) (logid:a8cce472) Performing image store
createTemplate async callback
y to launch console proxy
2020-03-16 15:22:04,678 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-46e91e19) (logid:a748b819) Zone 1 is ready to launch
secondary storage VM
2020-03-16 15:22:05,320 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Resetting hosts suitable for reconnect
2020-03-16 15:22:05,323 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Completed resetting hosts suitable for
reconnect
2020-03-16 15:22:05,323 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Acquiring hosts for clusters already owned
by this management server
2020-03-16 15:22:05,325 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Completed acquiring hosts for clusters
already owned by this management server
2020-03-16 15:22:05,325 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Acquiring hosts for clusters not owned by
any management server
2020-03-16 15:22:05,325 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-e03ac9e4) (logid:87f12d12) Completed acquiring hosts for clusters not
owned by any management server
2020-03-16 15:22:05,613 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-14:null) (logid:) SeqA 4-42: Processing Seq 4-42: { Cmd
, MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":87,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2020-03-16 15:22:05,623 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-14:null) (logid:) SeqA 4-42: Sending Seq 4-42: { Ans: ,
MgmtId: 8796757934110, via: 4, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2020-03-16 15:22:06,274 DEBUG [c.c.a.ApiServlet] (qtp504527234-14:ctx-9a48da8b)
(logid:fe9d2b1e) ===START=== 172.26.0.190 -- GET
command=queryAsyncJobResult&jobId=2fac8aa3-653b-4d69-8502-9b2da0fc4206&response=json&_=1584381583984
2020-03-16 15:22:06,283 DEBUG [c.c.a.ApiServer] (qtp504527234-14:ctx-9a48da8b
ctx-8c468fd0) (logid:fe9d2b1e) CIDRs from which account
'Acct[e8c8861d-5f9c-11ea-bb9d-080027a1c01e-admin]' is allowed to perform API
calls: 0.0.0.0/0,::/0
2020-03-16 15:22:06,294 DEBUG [c.c.a.ApiServlet] (qtp504527234-14:ctx-9a48da8b
ctx-8c468fd0) (logid:fe9d2b1e) ===END=== 172.26.0.190 -- GET
command=queryAsyncJobResult&jobId=2fac8aa3-653b-4d69-8502-9b2da0fc4206&response=json&_=1584381583984
2020-03-16 15:22:06,298 DEBUG [c.c.a.ApiServlet] (qtp504527234-12:ctx-6de5d048)
(logid:ca0fdf73) ===START=== 172.26.0.190 -- GET
command=listVirtualMachines&id=e360583b-48cc-4690-a730-dbc8993e4f04&response=json&_=1584381583985
2020-03-16 15:22:06,304 DEBUG [c.c.a.ApiServer] (qtp504527234-12:ctx-6de5d048
ctx-2a557c0b) (logid:ca0fdf73) CIDRs from which account
'Acct[e8c8861d-5f9c-11ea-bb9d-080027a1c01e-admin]' is allowed to perform API
calls: 0.0.0.0/0,::/0
2020-03-16 15:22:06,348 DEBUG [c.c.a.ApiServlet] (qtp504527234-12:ctx-6de5d048
ctx-2a557c0b) (logid:ca0fdf73) ===END=== 172.26.0.190 -- GET
command=listVirtualMachines&id=e360583b-48cc-4690-a730-dbc8993e4f04&response=json&_=1584381583985
2020-03-16 15:22:08,504 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-5993cfec) (logid:91d56cda) Begin cleanup expired
async-jobs
2020-03-16 15:22:08,509 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-5993cfec) (logid:91d56cda) End cleanup expired
async-jobs
2020-03-16 15:22:10,090 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru]
(Timer-8:ctx-c995a317) (logid:d0bfed48) getCommandHostDelegation: class
org.apache.cloudstack.storage.command.DownloadProgressCommand
2020-03-16 15:22:10,093 DEBUG [c.c.h.XenServerGuru] (Timer-8:ctx-c995a317)
(logid:d0bfed48) We are returning the default host to execute commands because
the command is not of Copy type.
2020-03-16 15:22:10,093 DEBUG [o.a.c.s.RemoteHostEndPoint]
(Timer-8:ctx-c995a317) (logid:d0bfed48) Sending command
org.apache.cloudstack.storage.command.DownloadProgressCommand to host: 3
2020-03-16 15:22:10,096 DEBUG [c.c.a.t.Request] (Timer-8:ctx-c995a317)
(logid:d0bfed48) Seq 3-7278661422760853572: Sending { Cmd , MgmtId:
8796757934110, via: 3(s-73-VM), Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.DownloadProgressCommand":{"jobId":"4252f6a6-a0c5-491b-b597-fa1987a9b9b1","request":"GET_STATUS","hvm":false,"description":"SystemVM
Template
(KVM)","checksum":"15ec268d0939a8fa0be1bc79f397a167","maxDownloadSizeInBytes":53687091200,"id":3,"resourceType":"TEMPLATE","installPath":"template/tmpl/1/3","_store":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://172.26.0.222/export/secondary","_role":"Image"}},"url":"http://download.cloudstack.org/systemvm/4.11/systemvmtemplate-4.11.3-kvm.qcow2.bz2","format":"QCOW2","accountId":1,"name":"routing-3","secUrl":"nfs://172.26.0.222/export/secondary","wait":0}}]
}
2020-03-16 15:22:10,146 DEBUG [c.c.a.t.Request] (AgentManager-Handler-15:null)
(logid:) Seq 3-7278661422760853572: Processing: { Ans: , MgmtId:
8796757934110, via: 3, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.storage.DownloadAnswer":{"jobId":"4252f6a6-a0c5-491b-b597-fa1987a9b9b1","downloadPct":74,"errorString":"
","downloadStatus":"DOWNLOAD_IN_PROGRESS","downloadPath":"/mnt/SecStorage/3bacb604-b035-378f-8f59-3a646c9dc0b4/template/tmpl/1/3/dnld5913098205028932528tmp_","installPath":"template/tmpl/1/3","templateSize":0,"templatePhySicalSize":0,"checkSum":"15ec268d0939a8fa0be1bc79f397a167","result":true,"details":"
","wait":0}}] }
2020-03-16 15:22:10,147 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl]
(RemoteHostEndPoint-3:ctx-46787815) (logid:a8cce472) Performing image store
createTemplate async callback
