Hi,

The root cause seems to be
"""
2024-01-30 16:32:03,185 DEBUG [c.c.n.r.NetworkHelperImpl]
(Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
(logid:baa568fc) KVM won't support system vm, skip it
"""

Please check the global setting and zone setting "router.template.kvm", and
verify if the template is good or not.

-Wei


On Tue, 30 Jan 2024 at 17:55, Kapil Bhuskute <[email protected]>
wrote:

> Hello Wei,
> I have ensured the systemvm template is also in ready state now. And tried
> to re-spin another instance, but it is still complaining for the same
> reason. And the Instance is going to Error state again.
>
> Logs indicate the same InsufficientServerCapacityException errors:
> [HOST]# egrep
> "job-2072|job-2073|9d85fa79-da41-4090-9411-54520792f89e|i-2-390-VM"
> /var/log/cloudstack/management/management-server.log
> 2024-01-30 16:32:01,766 INFO  [c.c.v.VirtualMachineManagerImpl]
> (qtp1789718525-14144:ctx-b7c95aac ctx-d6bcf85f) (logid:b68ac14f) allocating
> virtual machine from template:62077549-9c1f-442a-ad97-ce42cd7c63fe with
> hostname:i-2-390-VM and 1 networks
> 2024-01-30 16:32:01,767 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (qtp1789718525-14144:ctx-b7c95aac ctx-d6bcf85f) (logid:b68ac14f) Allocating
> entries for VM: VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> 2024-01-30 16:32:01,768 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (qtp1789718525-14144:ctx-b7c95aac ctx-d6bcf85f) (logid:b68ac14f) Allocating
> nics for VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> 2024-01-30 16:32:01,769 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (qtp1789718525-14144:ctx-b7c95aac ctx-d6bcf85f) (logid:b68ac14f) Allocating
> nic for vm VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> in network Network {"id": 247, "name": "10.252.1.x", "uuid":
> "f2971bd7-4635-48f2-8b05-75b5d5a4705c", "networkofferingid": 8} with
> requested profile NicProfile
> {"broadcastUri":null,"iPv4Address":null,"id":0,"reservationId":null,"vmId":0}
> 2024-01-30 16:32:01,791 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (qtp1789718525-14144:ctx-b7c95aac ctx-d6bcf85f) (logid:b68ac14f) Allocating
> disks for VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> 2024-01-30 16:32:01,791 INFO  [o.a.c.e.o.VolumeOrchestrator]
> (qtp1789718525-14144:ctx-b7c95aac ctx-d6bcf85f ctx-f0fd01cd)
> (logid:b68ac14f) Adding disk object [ROOT-390] to VM [VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}]
> 2024-01-30 16:32:01,800 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (qtp1789718525-14144:ctx-b7c95aac ctx-d6bcf85f) (logid:b68ac14f) Allocation
> completed for VM: VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> 2024-01-30 16:32:01,801 DEBUG [c.c.v.UserVmManagerImpl]
> (qtp1789718525-14144:ctx-b7c95aac ctx-d6bcf85f) (logid:b68ac14f)
> Successfully allocated DB entry for VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> 2024-01-30 16:32:01,819 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072) (logid:493589da) Add job-2072
> into job monitoring
> 2024-01-30 16:32:01,824 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (qtp1789718525-14144:ctx-b7c95aac ctx-d6bcf85f) (logid:b68ac14f) submit
> async job-2072, details: AsyncJobVO: {id:2072, userId: 2, accountId: 2,
> instanceType: VirtualMachine, instanceId: 390, cmd:
> org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin, cmdInfo:
> {"iptonetworklist[0].networkid":"f2971bd7-4635-48f2-8b05-75b5d5a4705c","hostid":"5e6f1b73-5f0a-4ab1-b424-42dc16fc9810","httpmethod":"GET","ctxAccountId":"2","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc","cmdEventType":"VM.CREATE","bootmode":"LEGACY","iothreadsenabled":"false","rootdisksize":"50","ctxStartEventId":"3911","id":"390","ctxDetails":"{\"interface
> com.cloud.offering.ServiceOffering\":\"abb92858-9eb9-45bb-8cce-9778113fe54f\",\"interface
> com.cloud.host.Host\":\"5e6f1b73-5f0a-4ab1-b424-42dc16fc9810\",\"interface
> com.cloud.dc.DataCenter\":\"bef7ac55-3bb8-4211-bbc7-1e708bb36083\",\"interface
> com.cloud.org.Cluster\":\"35c1a5be-5609-4a39-bcf8-1940c0fc3e64\",\"interface
> com.cloud.dc.Pod\":\"364522fe-d989-4cee-bc1c-7489aa54f113\",\"interface
> com.cloud.template.VirtualMachineTemplate\":\"62077549-9c1f-442a-ad97-ce42cd7c63fe\",\"interface
> com.cloud.vm.VirtualMachine\":\"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc\"}","dynamicscalingenabled":"true","keypairs":"","group":"App","keyboard":"us","boottype":"BIOS","clusterid":"35c1a5be-5609-4a39-bcf8-1940c0fc3e64","templateid":"62077549-9c1f-442a-ad97-ce42cd7c63fe","startvm":"true","serviceofferingid":"abb92858-9eb9-45bb-8cce-9778113fe54f","response":"json","ctxUserId":"2","displayname":"testnode01","name":"testnode01","zoneid":"bef7ac55-3bb8-4211-bbc7-1e708bb36083","podid":"364522fe-d989-4cee-bc1c-7489aa54f113","affinitygroupids":""},
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 229310345246465, completeMsid: null, lastUpdated:
> null, lastPolled: null, created: null, removed: null}
> 2024-01-30 16:32:01,826 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072) (logid:baa568fc) Executing
> AsyncJobVO: {id:2072, userId: 2, accountId: 2, instanceType:
> VirtualMachine, instanceId: 390, cmd:
> org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin, cmdInfo:
> {"iptonetworklist[0].networkid":"f2971bd7-4635-48f2-8b05-75b5d5a4705c","hostid":"5e6f1b73-5f0a-4ab1-b424-42dc16fc9810","httpmethod":"GET","ctxAccountId":"2","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc","cmdEventType":"VM.CREATE","bootmode":"LEGACY","iothreadsenabled":"false","rootdisksize":"50","ctxStartEventId":"3911","id":"390","ctxDetails":"{\"interface
> com.cloud.offering.ServiceOffering\":\"abb92858-9eb9-45bb-8cce-9778113fe54f\",\"interface
> com.cloud.host.Host\":\"5e6f1b73-5f0a-4ab1-b424-42dc16fc9810\",\"interface
> com.cloud.dc.DataCenter\":\"bef7ac55-3bb8-4211-bbc7-1e708bb36083\",\"interface
> com.cloud.org.Cluster\":\"35c1a5be-5609-4a39-bcf8-1940c0fc3e64\",\"interface
> com.cloud.dc.Pod\":\"364522fe-d989-4cee-bc1c-7489aa54f113\",\"interface
> com.cloud.template.VirtualMachineTemplate\":\"62077549-9c1f-442a-ad97-ce42cd7c63fe\",\"interface
> com.cloud.vm.VirtualMachine\":\"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc\"}","dynamicscalingenabled":"true","keypairs":"","group":"App","keyboard":"us","boottype":"BIOS","clusterid":"35c1a5be-5609-4a39-bcf8-1940c0fc3e64","templateid":"62077549-9c1f-442a-ad97-ce42cd7c63fe","startvm":"true","serviceofferingid":"abb92858-9eb9-45bb-8cce-9778113fe54f","response":"json","ctxUserId":"2","displayname":"testnode01","name":"testnode01","zoneid":"bef7ac55-3bb8-4211-bbc7-1e708bb36083","podid":"364522fe-d989-4cee-bc1c-7489aa54f113","affinitygroupids":""},
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 229310345246465, completeMsid: null, lastUpdated:
> null, lastPolled: null, created: null, removed: null}
> 2024-01-30 16:32:01,838 DEBUG [c.c.n.NetworkModelImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Service SecurityGroup is not supported in the network id=247
> 2024-01-30 16:32:01,840 DEBUG [c.c.n.NetworkModelImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Service SecurityGroup is not supported in the network id=247
> 2024-01-30 16:32:01,841 DEBUG [c.c.v.UserVmManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Destination Host to deploy the VM is specified, specifying a deployment
> plan to deploy the VM
> 2024-01-30 16:32:01,842 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Host: 1 has cpu capability (cpu:96, speed:2200) to support requested CPU: 4
> and requested speed: 1000
> 2024-01-30 16:32:01,842 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Checking if host: 1 has enough capacity for requested CPU: 4000 and
> requested RAM: (16.00 GB) 17179869184 , cpuOverprovisioningFactor: 1.0
> 2024-01-30 16:32:01,842 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Hosts's actual total CPU: 211200 and CPU after applying overprovisioning:
> 211200
> 2024-01-30 16:32:01,842 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> considerReservedCapacity isfalse , not considering reserved capacity for
> calculating free capacity
> 2024-01-30 16:32:01,842 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Free CPU: 210700 , Requested CPU: 4000
> 2024-01-30 16:32:01,842 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Free RAM: (1004.57 GB) 1078650142720 , Requested RAM: (16.00 GB) 17179869184
> 2024-01-30 16:32:01,842 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Host has enough CPU and RAM available
> 2024-01-30 16:32:01,842 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> STATS: Can alloc CPU from host: 1, used: 500, reserved: 0, actual total:
> 211200, total with overprovisioning: 211200; requested
> cpu:4000,alloc_from_last_host?:false ,considerReservedCapacity?: false
> 2024-01-30 16:32:01,842 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> STATS: Can alloc MEM from host: 1, used: (512.00 MB) 536870912, reserved:
> (0 bytes) 0, total: (1005.07 GB) 1079187013632; requested mem: (16.00 GB)
> 17179869184, alloc_from_last_host?: false , considerReservedCapacity?: false
> 2024-01-30 16:32:01,848 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Adding pods to avoid lists for non-explicit VM deployment: []
> 2024-01-30 16:32:01,848 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Adding clusters to avoid lists for non-explicit VM deployment: []
> 2024-01-30 16:32:01,848 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Adding hosts to avoid lists for non-explicit VM deployment: []
> 2024-01-30 16:32:01,848 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> DeploymentPlanner allocation algorithm: null
> 2024-01-30 16:32:01,848 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1,
> requested cpu: 4000, requested ram: (16.00 GB) 17179869184
> 2024-01-30 16:32:01,848 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc) Is
> ROOT volume READY (pool already allocated)?: No
> 2024-01-30 16:32:01,849 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> DeploymentPlan has host_id specified, choosing this host: 1
> 2024-01-30 16:32:01,850 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Looking for suitable pools for this host under zone: 1, pod: 1, cluster: 1
> 2024-01-30 16:32:01,851 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Checking suitable pools for volume (Id, Type): (261,ROOT)
> 2024-01-30 16:32:01,851 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc) We
> need to allocate new storagepool for this volume
> 2024-01-30 16:32:01,851 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Calling StoragePoolAllocators to find suitable pools
> 2024-01-30 16:32:01,852 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> LocalStoragePoolAllocator is returning null since the disk profile does not
> use local storage and bypassStorageTypeCheck is false.
> 2024-01-30 16:32:01,852 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Looking for pools in dc [1], pod [1], cluster [1], and having tags [[nfs]].
> Disabled pools will be ignored.
> 2024-01-30 16:32:01,852 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Found pools [[Pool[2|NetworkFilesystem]]] that match with tags [[nfs]].
> 2024-01-30 16:32:01,853 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Checking if storage pool is suitable, name: vhs01-nfs ,poolId: 2
> 2024-01-30 16:32:01,853 INFO  [c.c.s.StorageManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Storage pool vhs01-nfs (2) does not supply IOPS capacity, assuming enough
> capacity
> 2024-01-30 16:32:01,854 DEBUG [c.c.s.StorageManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Checking pool 2 for storage, totalSize: 799140741120, usedBytes:
> 144575561728, usedPct: 0.1809137668608618, disable threshold: 0.85
> 2024-01-30 16:32:01,854 DEBUG [c.c.s.StorageManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Destination pool id: 2
> 2024-01-30 16:32:01,858 DEBUG [c.c.s.StorageManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Pool ID for the volume with ID 261 is null
> 2024-01-30 16:32:01,859 DEBUG [c.c.s.StorageManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Found storage pool vhs01-nfs of type NetworkFilesystem with
> overprovisioning factor 2
> 2024-01-30 16:32:01,859 DEBUG [c.c.s.StorageManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Total over provisioned capacity calculated is 2 * (744.26 GB) 799140741120
> 2024-01-30 16:32:01,859 DEBUG [c.c.s.StorageManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Total capacity of the pool vhs01-nfs with ID 2 is (1.4536 TB) 1598281482240
> 2024-01-30 16:32:01,859 DEBUG [c.c.s.StorageManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Checking pool: 2 for storage allocation , maxSize : (1.4536 TB)
> 1598281482240, totalAllocatedSize : (839.77 GB) 901691868672, askingSize :
> (50.00 GB) 53687091200, allocated disable threshold: 0.85
> 2024-01-30 16:32:01,859 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> ClusterScopeStoragePoolAllocator is returning [1] suitable storage pools
> [[{"name":"vhs01-nfs","uuid":"eb29dd4c-7cc6-3f6f-bc36-470d6a03621e"}]].
> 2024-01-30 16:32:01,860 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Volume encryption requirements are met by provided host Host
> {"id":1,"name":"vhs05.lego05.ops.in01.qualys.com
> ","type":"Routing","uuid":"5e6f1b73-5f0a-4ab1-b424-42dc16fc9810"}
> 2024-01-30 16:32:01,860 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Trying to find a potenial host and associated storage pools from the
> suitable host/pool lists for this VM
> 2024-01-30 16:32:01,861 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Checking if host: 1 can access any suitable storage pool for volume: ROOT
> 2024-01-30 16:32:01,861 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Host: 1 can access pool: 2
> 2024-01-30 16:32:01,861 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Found a potential host id: 1 name: vhs05.lego05.ops.in01.qualys.com and
> associated storage pools for this VM
> 2024-01-30 16:32:01,862 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Returning Deployment Destination:
> Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
> : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(261|ROOT-->Pool(2))]
> 2024-01-30 16:32:01,863 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> start parameter value of enterHardwareSetup == null during processing of
> queued job
> 2024-01-30 16:32:01,866 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Sync job-2073 execution on object VmWorkJobQueue.390
> 2024-01-30 16:32:03,128 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-765d0430) (logid:5dcc7b22) Schedule queued
> job-2073
> 2024-01-30 16:32:03,129 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073) (logid:49b94350) Add
> job-2073 into job monitoring
> 2024-01-30 16:32:03,132 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073) (logid:baa568fc)
> Executing AsyncJobVO: {id:2073, userId: 2, accountId: 2, instanceType:
> null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
> rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAABhnQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAXBzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAAAFxAH4ACnBwcHEAfgAKcHNyABFqYXZhLnV0aWwuSGFzaE1hcAUH2sHDFmDRAwACRgAKbG9hZEZhY3RvckkACXRocmVzaG9sZHhwP0AAAAAAAAx3CAAAABAAAAABdAAKVm1QYXNzd29yZHQAHHJPMEFCWFFBRG5OaGRtVmtYM0JoYzNOM2IzSmt4cA,
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 229310345246465, completeMsid: null, lastUpdated:
> null, lastPolled: null, created: Tue Jan 30 16:32:01 UTC 2024, removed:
> null}
> 2024-01-30 16:32:03,132 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073) (logid:baa568fc) Run
> VM work job: com.cloud.vm.VmWorkStart for VM 390, job origin: 2072
> 2024-01-30 16:32:03,133 DEBUG [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Execute VM work job:
> com.cloud.vm.VmWorkStart{"dcId":1,"podId":1,"clusterId":1,"hostId":1,"rawParams":{"VmPassword":"rO0ABXQADnNhdmVkX3Bhc3N3b3Jk"},"userId":2,"accountId":2,"vmId":390,"handlerName":"VirtualMachineManagerImpl"}
> 2024-01-30 16:32:03,133 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) orchestrating VM start for 'i-2-390-VM'
> com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d<mailto:
> com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d> set to null
> 2024-01-30 16:32:03,135 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> state transited from [Stopped] to [Starting] with event [StartRequested].
> VM's original host: null, new host: null, host before state transition: null
> 2024-01-30 16:32:03,136 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Successfully transitioned to start state for VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> reservation id = e270b570-b7ba-419f-aa87-dc30b06ba38d
> 2024-01-30 16:32:03,137 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) advanceStart: DeploymentPlan is provided, using dcId:1,
> podId: 1, clusterId: 1, hostId: 1, poolId: null
> 2024-01-30 16:32:03,137 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Deploy avoids pods: null, clusters: null, hosts: null
> 2024-01-30 16:32:03,138 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) VM start attempt #1
> 2024-01-30 16:32:03,140 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Adding pods to avoid lists for non-explicit VM deployment:
> []
> 2024-01-30 16:32:03,140 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Adding clusters to avoid lists for non-explicit VM
> deployment: []
> 2024-01-30 16:32:03,140 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Adding hosts to avoid lists for non-explicit VM
> deployment: []
> 2024-01-30 16:32:03,140 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) DeploymentPlanner allocation algorithm: null
> 2024-01-30 16:32:03,140 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Trying to allocate a host and storage pools from dc:1,
> pod:1,cluster:1, requested cpu: 4000, requested ram: (16.00 GB) 17179869184
> 2024-01-30 16:32:03,140 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Is ROOT volume READY (pool already allocated)?: No
> 2024-01-30 16:32:03,142 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) DeploymentPlan has host_id specified, choosing this host: 1
> 2024-01-30 16:32:03,142 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Looking for suitable pools for this host under zone: 1,
> pod: 1, cluster: 1
> 2024-01-30 16:32:03,143 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Checking suitable pools for volume (Id, Type): (261,ROOT)
> 2024-01-30 16:32:03,143 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) We need to allocate new storagepool for this volume
> 2024-01-30 16:32:03,143 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Calling StoragePoolAllocators to find suitable pools
> 2024-01-30 16:32:03,144 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) LocalStoragePoolAllocator is returning null since the disk
> profile does not use local storage and bypassStorageTypeCheck is false.
> 2024-01-30 16:32:03,144 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Looking for pools in dc [1], pod [1], cluster [1], and
> having tags [[nfs]]. Disabled pools will be ignored.
> 2024-01-30 16:32:03,145 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Found pools [[Pool[2|NetworkFilesystem]]] that match with
> tags [[nfs]].
> 2024-01-30 16:32:03,145 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Checking if storage pool is suitable, name: vhs01-nfs
> ,poolId: 2
> 2024-01-30 16:32:03,146 INFO  [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Storage pool vhs01-nfs (2) does not supply IOPS capacity,
> assuming enough capacity
> 2024-01-30 16:32:03,146 DEBUG [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Checking pool 2 for storage, totalSize: 799140741120,
> usedBytes: 144575561728, usedPct: 0.1809137668608618, disable threshold:
> 0.85
> 2024-01-30 16:32:03,146 DEBUG [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Destination pool id: 2
> 2024-01-30 16:32:03,151 DEBUG [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Pool ID for the volume with ID 261 is null
> 2024-01-30 16:32:03,152 DEBUG [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Found storage pool vhs01-nfs of type NetworkFilesystem
> with overprovisioning factor 2
> 2024-01-30 16:32:03,152 DEBUG [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Total over provisioned capacity calculated is 2 * (744.26
> GB) 799140741120
> 2024-01-30 16:32:03,152 DEBUG [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Total capacity of the pool vhs01-nfs with ID 2 is (1.4536
> TB) 1598281482240
> 2024-01-30 16:32:03,152 DEBUG [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Checking pool: 2 for storage allocation , maxSize :
> (1.4536 TB) 1598281482240, totalAllocatedSize : (839.77 GB) 901691868672,
> askingSize : (50.00 GB) 53687091200, allocated disable threshold: 0.85
> 2024-01-30 16:32:03,152 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) ClusterScopeStoragePoolAllocator is returning [1] suitable
> storage pools
> [[{"name":"vhs01-nfs","uuid":"eb29dd4c-7cc6-3f6f-bc36-470d6a03621e"}]].
> 2024-01-30 16:32:03,153 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Volume encryption requirements are met by provided host
> Host {"id":1,"name":"vhs05.lego05.ops.in01.qualys.com
> ","type":"Routing","uuid":"5e6f1b73-5f0a-4ab1-b424-42dc16fc9810"}
> 2024-01-30 16:32:03,153 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Trying to find a potenial host and associated storage
> pools from the suitable host/pool lists for this VM
> 2024-01-30 16:32:03,153 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Checking if host: 1 can access any suitable storage pool
> for volume: ROOT
> 2024-01-30 16:32:03,154 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Host: 1 can access pool: 2
> 2024-01-30 16:32:03,154 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Found a potential host id: 1 name:
> vhs05.lego05.ops.in01.qualys.com and associated storage pools for this VM
> 2024-01-30 16:32:03,154 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Returning Deployment Destination:
> Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
> : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(261|ROOT-->Pool(2))]
> 2024-01-30 16:32:03,155 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Deployment found - Attempt #1 - P0=VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"},
> P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
> : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(261|ROOT-->Pool(2))]
> 2024-01-30 16:32:03,158 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> state transited from [Starting] to [Starting] with event [OperationRetry].
> VM's original host: null, new host: Host {"id":1,"name":"
> vhs05.lego05.ops.in01.qualys.com","type":"Routing","uuid":"5e6f1b73-5f0a-4ab1-b424-42dc16fc9810"},
> host before state transition: null
> 2024-01-30 16:32:03,160 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Hosts's actual total CPU: 211200 and CPU after applying
> overprovisioning: 211200
> 2024-01-30 16:32:03,160 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) We are allocating VM, increasing the used capacity of this
> host:1
> 2024-01-30 16:32:03,160 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Current Used CPU: 500 , Free CPU:210700 ,Requested CPU:
> 4000
> 2024-01-30 16:32:03,160 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Current Used RAM: (512.00 MB) 536870912 , Free
> RAM:(1004.57 GB) 1078650142720 ,Requested RAM: (16.00 GB) 17179869184
> 2024-01-30 16:32:03,160 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) CPU STATS after allocation: for host: 1, old used: 500,
> old reserved: 0, actual total: 211200, total with overprovisioning: 211200;
> new used:4500, reserved:0; requested cpu:4000,alloc_from_last:false
> 2024-01-30 16:32:03,160 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) RAM STATS after allocation: for host: 1, old used: (512.00
> MB) 536870912, old reserved: (0 bytes) 0, total: (1005.07 GB)
> 1079187013632; new used: (16.50 GB) 17716740096, reserved: (0 bytes) 0;
> requested mem: (16.00 GB) 17179869184,alloc_from_last:false
> 2024-01-30 16:32:03,160 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Host: 1 has cpu capability (cpu:96, speed:2200) to support
> requested CPU: 4 and requested speed: 1000
> 2024-01-30 16:32:03,160 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Checking if host: 1 has enough capacity for requested CPU:
> 4000 and requested RAM: (16.00 GB) 17179869184 , cpuOverprovisioningFactor:
> 1.0
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Hosts's actual total CPU: 211200 and CPU after applying
> overprovisioning: 211200
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) We need to allocate to the last host again, so checking if
> there is enough reserved capacity
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Reserved CPU: 0 , Requested CPU: 4000
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Reserved RAM: (0 bytes) 0 , Requested RAM: (16.00 GB)
> 17179869184
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) STATS: Failed to alloc resource from host: 1 reservedCpu:
> 0, requested cpu: 4000, reservedMem: (0 bytes) 0, requested mem: (16.00 GB)
> 17179869184
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Host does not have enough reserved CPU available, cannot
> allocate to this host.
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Checking if host: 1 has enough capacity for requested CPU:
> 4000 and requested RAM: (16.00 GB) 17179869184 , cpuOverprovisioningFactor:
> 1.0
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Hosts's actual total CPU: 211200 and CPU after applying
> overprovisioning: 211200
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Free CPU: 210700 , Requested CPU: 4000
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Free RAM: (1004.57 GB) 1078650142720 , Requested RAM:
> (16.00 GB) 17179869184
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Host has enough CPU and RAM available
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) STATS: Can alloc CPU from host: 1, used: 500, reserved: 0,
> actual total: 211200, total with overprovisioning: 211200; requested
> cpu:4000,alloc_from_last_host?:false ,considerReservedCapacity?: true
> 2024-01-30 16:32:03,161 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) STATS: Can alloc MEM from host: 1, used: (512.00 MB)
> 536870912, reserved: (0 bytes) 0, total: (1005.07 GB) 1079187013632;
> requested mem: (16.00 GB) 17179869184, alloc_from_last_host?: false ,
> considerReservedCapacity?: true
> 2024-01-30 16:32:03,164 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Network id=247 is already implemented
> 2024-01-30 16:32:03,168 DEBUG [c.c.n.NetworkModelImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Service SecurityGroup is not supported in the network
> id=247
> 2024-01-30 16:32:03,169 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Changing active number of nics for network id=247 on 1
> 2024-01-30 16:32:03,172 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Asking VirtualRouter to prepare for
> Nic[411-390-null-10.252.1.5]
> 2024-01-30 16:32:03,180 DEBUG [o.a.c.n.r.d.RouterDeploymentDefinition]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Verifying router service offering with uuid :
> 2024-01-30 16:32:03,183 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Host: 1 has cpu capability (cpu:96, speed:2200) to support
> requested CPU: 1 and requested speed: 500
> 2024-01-30 16:32:03,183 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Checking if host: 1 has enough capacity for requested CPU:
> 500 and requested RAM: (256.00 MB) 268435456 , cpuOverprovisioningFactor:
> 1.0
> 2024-01-30 16:32:03,183 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Hosts's actual total CPU: 211200 and CPU after applying
> overprovisioning: 211200
> 2024-01-30 16:32:03,183 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) considerReservedCapacity isfalse , not considering
> reserved capacity for calculating free capacity
> 2024-01-30 16:32:03,183 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Free CPU: 206700 , Requested CPU: 500
> 2024-01-30 16:32:03,183 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Free RAM: (988.57 GB) 1061470273536 , Requested RAM:
> (256.00 MB) 268435456
> 2024-01-30 16:32:03,183 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Host has enough CPU and RAM available
> 2024-01-30 16:32:03,183 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) STATS: Can alloc CPU from host: 1, used: 4500, reserved:
> 0, actual total: 211200, total with overprovisioning: 211200; requested
> cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: false
> 2024-01-30 16:32:03,183 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) STATS: Can alloc MEM from host: 1, used: (16.50 GB)
> 17716740096, reserved: (0 bytes) 0, total: (1005.07 GB) 1079187013632;
> requested mem: (256.00 MB) 268435456, alloc_from_last_host?: false ,
> considerReservedCapacity?: false
> 2024-01-30 16:32:03,183 DEBUG [c.c.n.r.NetworkHelperImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Host Host {"id":1,"name":"
> vhs05.lego05.ops.in01.qualys.com","type":"Routing","uuid":"5e6f1b73-5f0a-4ab1-b424-42dc16fc9810"}
> has enough capacity for the router
> 2024-01-30 16:32:03,184 DEBUG [c.c.n.r.NetworkHelperImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Allocating the VR with id=391 in datacenter Zone {"id":
> "1", "name": "IN01", "uuid": "bef7ac55-3bb8-4211-bbc7-1e708bb36083"} with
> the hypervisor type KVM
> 2024-01-30 16:32:03,185 DEBUG [c.c.n.r.NetworkHelperImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) KVM won't support system vm, skip it
> 2024-01-30 16:32:03,186 DEBUG [o.a.c.n.r.d.RouterDeploymentDefinition]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Lock is released for network id 247 as a part of router
> startup in
> Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
> : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(261|ROOT-->Pool(2))]
> 2024-01-30 16:32:03,186 WARN  [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Unable to contact resource.
> 2024-01-30 16:32:03,187 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Cleaning up resources for the vm VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> in Starting state
> 2024-01-30 16:32:03,190 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> is a [User], returning null for control Nic IP.
> 2024-01-30 16:32:03,191 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Seq 1-7704251587547391155: Sending  { Cmd , MgmtId:
> 229310345246465, via: 1(vhs05.lego05.ops.in01.qualys.com), Ver: v1,
> Flags: 100011,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","forceStop":"false","vlanToPersistenceMap":{"101":"true"},"volumesToDisconnect":[],"vmName":"i-2-390-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}]
> }
> 2024-01-30 16:32:03,330 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Seq 1-7704251587547391155: Received:  { Ans: , MgmtId:
> 229310345246465, via: 1(vhs05.lego05.ops.in01.qualys.com), Ver: v1,
> Flags: 10, { StopAnswer } }
> 2024-01-30 16:32:03,334 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Changing active number of nics for network id=247 on -1
> 2024-01-30 16:32:03,336 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Successfully released network resources for the VM VM
> instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> in Starting state
> 2024-01-30 16:32:03,337 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Successfully released storage resources for the VM VM
> instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> in Starting state
> 2024-01-30 16:32:03,337 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Successfully cleaned up resources for the VM VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> in Starting state
> 2024-01-30 16:32:03,338 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) VM start attempt #2
> 2024-01-30 16:32:03,340 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Adding pods to avoid lists for non-explicit VM deployment:
> []
> 2024-01-30 16:32:03,340 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Adding clusters to avoid lists for non-explicit VM
> deployment: []
> 2024-01-30 16:32:03,340 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Adding hosts to avoid lists for non-explicit VM
> deployment: []
> 2024-01-30 16:32:03,340 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) DeploymentPlanner allocation algorithm: null
> 2024-01-30 16:32:03,340 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Trying to allocate a host and storage pools from dc:1,
> pod:1,cluster:1, requested cpu: 4000, requested ram: (16.00 GB) 17179869184
> 2024-01-30 16:32:03,340 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Is ROOT volume READY (pool already allocated)?: No
> 2024-01-30 16:32:03,341 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) DeploymentPlan has host_id specified, choosing this host: 1
> 2024-01-30 16:32:03,341 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) The specified host is in avoid set
> 2024-01-30 16:32:03,341 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Cannot deploy to specified host, returning.
> 2024-01-30 16:32:03,345 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> state transited from [Starting] to [Stopped] with event [OperationFailed].
> VM's original host: null, new host: null, host before state transition:
> Host {"id":1,"name":"vhs05.lego05.ops.in01.qualys.com
> ","type":"Routing","uuid":"5e6f1b73-5f0a-4ab1-b424-42dc16fc9810"}
> 2024-01-30 16:32:03,347 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Hosts's actual total CPU: 211200 and CPU after applying
> overprovisioning: 211200
> 2024-01-30 16:32:03,347 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Hosts's actual total RAM: (1005.07 GB) 1079186989056 and
> RAM after applying overprovisioning: (1005.07 GB) 1079187013632
> 2024-01-30 16:32:03,347 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) release cpu from host: 1, old used: 4500,reserved: 0,
> actual total: 211200, total with overprovisioning: 211200; new used:
> 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2024-01-30 16:32:03,347 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) release mem from host: 1, old used: (16.50 GB)
> 17716740096,reserved: (0 bytes) 0, total: (1005.07 GB) 1079187013632; new
> used: (512.00 MB) 536870912,reserved:(0 bytes) 0; movedfromreserved:
> false,moveToReserveredfalse
> 2024-01-30 16:32:03,350 ERROR [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Invocation exception, caused by:
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}Scope=interface
> com.cloud.dc.DataCenter; id=1
> 2024-01-30 16:32:03,350 INFO  [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073 ctx-32c09872)
> (logid:baa568fc) Rethrow exception
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}Scope=interface
> com.cloud.dc.DataCenter; id=1
> 2024-01-30 16:32:03,350 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073) (logid:baa568fc)
> Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 390, job
> origin: 2072
> 2024-01-30 16:32:03,350 ERROR [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073) (logid:baa568fc)
> Unable to complete AsyncJobVO: {id:2073, userId: 2, accountId: 2,
> instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart,
> cmdInfo:
> rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAABhnQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAXBzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAAAFxAH4ACnBwcHEAfgAKcHNyABFqYXZhLnV0aWwuSGFzaE1hcAUH2sHDFmDRAwACRgAKbG9hZEZhY3RvckkACXRocmVzaG9sZHhwP0AAAAAAAAx3CAAAABAAAAABdAAKVm1QYXNzd29yZHQAHHJPMEFCWFFBRG5OaGRtVmtYM0JoYzNOM2IzSmt4cA,
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 229310345246465, completeMsid: null, lastUpdated:
> null, lastPolled: null, created: Tue Jan 30 16:32:01 UTC 2024, removed:
> null}, job origin:2072
> com.cloud.exception.InsufficientServerCapacityException: Unable to create
> a deployment for VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}Scope=interface
> com.cloud.dc.DataCenter; id=1
>
> 2024-01-30 16:32:03,351 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073) (logid:baa568fc)
> Publish async job-2073 complete on message bus
> 2024-01-30 16:32:03,351 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073) (logid:baa568fc)
> Wake up jobs related to job-2073
> 2024-01-30 16:32:03,351 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073) (logid:baa568fc)
> Update db status for job-2073
> 2024-01-30 16:32:03,351 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073) (logid:baa568fc)
> Wake up jobs joined with job-2073 and disjoin all subjobs created from job-
> 2073
> 2024-01-30 16:32:03,352 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073) (logid:baa568fc)
> Done executing com.cloud.vm.VmWorkStart for job-2073
> 2024-01-30 16:32:03,353 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
> (Work-Job-Executor-155:ctx-7c14ec55 job-2072/job-2073) (logid:baa568fc)
> Remove job-2073 from job monitoring
> 2024-01-30 16:32:03,355 DEBUG [c.c.v.UserVmManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Destroying vm VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> as it failed to create on Host with Id:1
> 2024-01-30 16:32:03,356 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc) VM
> instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}
> state transited from [Stopped] to [Error] with event
> [OperationFailedToError]. VM's original host: null, new host: null, host
> before state transition: null
> 2024-01-30 16:32:03,359 DEBUG [c.c.s.d.VolumeDaoImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Removing volume 261 from DB
> 2024-01-30 16:32:03,361 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Updating resource Type = volume count for Account = 2 Operation =
> decreasing Amount = 1
> 2024-01-30 16:32:03,362 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Updating resource Type = primary_storage count for Account = 2 Operation =
> decreasing Amount = (50.00 GB) 53687091200
> 2024-01-30 16:32:03,364 WARN  [c.c.a.AlertManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> alertType=[8] dataCenterId=[1] podId=[1] clusterId=[null] message=[Failed
> to deploy Vm with Id: 390, on Host with Id: 1].
> 2024-01-30 16:32:03,366 WARN  [c.c.a.AlertManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc) No
> recipients set in global setting 'alert.email.addresses', skipping sending
> alert with subject [Failed to deploy Vm with Id: 390, on Host with Id: 1]
> and content [Failed to deploy Vm with Id: 390, on Host with Id: 1].
> 2024-01-30 16:32:03,366 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Updating resource Type = user_vm count for Account = 2 Operation =
> decreasing Amount = 1
> 2024-01-30 16:32:03,367 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Updating resource Type = cpu count for Account = 2 Operation = decreasing
> Amount = 4
> 2024-01-30 16:32:03,369 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072 ctx-11fd8dea) (logid:baa568fc)
> Updating resource Type = memory count for Account = 2 Operation =
> decreasing Amount = 16384
> 2024-01-30 16:32:03,371 ERROR [c.c.a.ApiAsyncJobDispatcher]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072) (logid:baa568fc) Unexpected
> exception while executing
> org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin
> com.cloud.utils.exception.CloudRuntimeException: Unable to start a VM
> [98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc] due to [Unable to create a
> deployment for VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}].
> Caused by: com.cloud.exception.InsufficientServerCapacityException: Unable
> to create a deployment for VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}Scope=interface
> com.cloud.dc.DataCenter; id=1
> 2024-01-30 16:32:03,372 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-9:ctx-a5c8e722 job-2072) (logid:baa568fc) Complete async
> job-2072, jobStatus: FAILED, resultCode: 530, result:
> org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":"530","errortext":"Unable
> to start a VM [98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc] due to [Unable to
> create a deployment for VM instance
> {"id":390,"instanceName":"i-2-390-VM","type":"User","uuid":"98e8bfaa-4bd2-4e23-94ca-b1005a9cf4bc"}]."}
>
>
> Kapil Bhuskute
>
>

Reply via email to