Hi Marciel, The primary storage added in the CS is the local storage of the KVM host. The compute offering selected has Storage Type: shared and so the deployment failed with no suitable storage pools. Create a new compute and disk offerings with Storage Type: local and use that for VM deployment.
Thanks, Suresh On Tue, Mar 17, 2020 at 1:45 AM Marciel Bonamigo < [email protected]> wrote: > MariaDB [cloud]> SELECT * FROM storage_pool; > > +----+---------------------------+--------------------------------------+------------+------+----------------+--------+------------+------------+----------------+--------------+-----------+-------------------------+---------------------+---------+-------------+--------+-----------------------+-------+------------+---------+---------------+ > | id | name | uuid | > pool_type | port | data_center_id | pod_id | cluster_id | used_bytes | > capacity_bytes | host_address | user_info | path | > created | removed | update_time | status | > storage_provider_name | scope | hypervisor | managed | capacity_iops | > > +----+---------------------------+--------------------------------------+------------+------+----------------+--------+------------+------------+----------------+--------------+-----------+-------------------------+---------------------+---------+-------------+--------+-----------------------+-------+------------+---------+---------------+ > | 1 | kvm-lab-01-local-fdf04200 | fdf04200-8e76-4fd6-9045-18c1f7b8924a | > Filesystem | 0 | 1 | 1 | 1 | 8382685184 | > 53660876800 | 172.26.0.222 | NULL | /var/lib/libvirt/images | > 2020-03-06 11:44:24 | NULL | NULL | Up | DefaultPrimary > | HOST | NULL | 0 | NULL | > > +----+---------------------------+--------------------------------------+------------+------+----------------+--------+------------+------------+----------------+--------------+-----------+-------------------------+---------------------+---------+-------------+--------+-----------------------+-------+------------+---------+---------------+ > > On Tue, Mar 17, 2020 at 1:45 AM Marciel Bonamigo < [email protected]> wrote: > compute offering: > Small Instance > Storage Type shared > Provisioning Type thin > # of CPU Cores 1 > CPU (in MHz) 500 MHz > Memory (in MB) 512.00 MB > > Disk Offering: > Description Small Disk, 5 GB > Custom Disk Size No > Disk Size (in GB) 5 > Custom IOPS > Min IOPS N/A > Max IOPS N/A > > > I selected as very basic standard offers. > > I just registered an Ubuntu ISO and gave the same error. > > storage.pool.allocators.exclude > Extensions to exclude from being > registered > GCStorage > > storage.pool.allocators.order > The order of precedence for the extensions > > > LocalStorage,ClusterScopeStoragePoolAllocator,ZoneWideStoragePoolAllocator > > storage.pool.max.waitseconds > Timeout (in seconds) to synchronize storage > pool operations. > 3600 > > pool.storage.allocated.capacity.disablethreshold > 0.85 > > pool.storage.capacity.disablethreshold > 0.85 > > > Marciel, > thanks > On Tue, Mar 17, 2020 at 12:38 AM Suresh Kumar Anaparti < [email protected]> wrote: > Hi Marciel, > > Based on the logs shared, CS couldn't locate suitable storage pool for > Root disk of the VM in dc: 1, pod:1, cluster:1. Can you share the compute > offering details selected for the VM and storage_pool table to check the > issue. > > Thanks, > Suresh > > On Mon, Mar 16, 2020 at 11:59 PM Marciel Bonamigo < > [email protected]> wrote: > >> 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 >> >> >>
