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