Hi,
thank you for the quick responses.
@Slavka is right. I tried the suggestions in the advisory but it didn't
work.
I am actually doing a single machine deployment. One thing is that, when I
try to attach a volume with the attach volume button, no vm is displayed in
the vm drop down.
The vm status is: Error
I'm getting this when I try to create new instance
No destination found for a deployment for VM instance
agent-log:
>
> 2022-08-21 12:39:32,721 INFO [cloud.agent.Agent] (Agent-Handler-3:null)
> (logid:) Reconnecting to host:192.168.122.10
> 2022-08-21 12:39:32,721 INFO [utils.nio.NioClient] (Agent-Handler-3:null)
> (logid:) Connecting to 192.168.122.10:8250
> 2022-08-21 12:39:32,721 WARN [utils.nio.NioConnection]
> (Agent-Handler-3:null) (logid:) Unable to connect to remote: is there a
> server running on port 8250
> 2022-08-21 12:39:37,722 INFO [cloud.agent.Agent] (Agent-Handler-3:null)
> (logid:) Reconnecting to host:192.168.122.10
> 2022-08-21 12:39:37,722 INFO [utils.nio.NioClient] (Agent-Handler-3:null)
> (logid:) Connecting to 192.168.122.10:8250
> 2022-08-21 12:39:37,723 WARN [utils.nio.NioConnection]
> (Agent-Handler-3:null) (logid:) Unable to connect to remote: is there a
> server running on port 8250
> 2022-08-21 12:39:42,723 INFO [cloud.agent.Agent] (Agent-Handler-3:null)
> (logid:) Reconnecting to host:192.168.122.10
> 2022-08-21 12:39:42,724 INFO [utils.nio.NioClient] (Agent-Handler-3:null)
> (logid:) Connecting to 192.168.122.10:8250
> 2022-08-21 12:39:42,724 WARN [utils.nio.NioConnection]
> (Agent-Handler-3:null) (logid:) Unable to connect to remote: is there a
> server running on port 8250
> 2022-08-21 12:39:47,725 INFO [cloud.agent.Agent] (Agent-Handler-3:null)
> (logid:) Reconnecting to host:192.168.122.10
> 2022-08-21 12:39:47,725 INFO [utils.nio.NioClient] (Agent-Handler-3:null)
> (logid:) Connecting to 192.168.122.10:8250
> 2022-08-21 12:39:47,726 WARN [utils.nio.NioConnection]
> (Agent-Handler-3:null) (logid:) Unable to connect to remote: is there a
> server running on port 8250
> 2022-08-21 12:39:52,726 INFO [cloud.agent.Agent] (Agent-Handler-3:null)
> (logid:) Reconnecting to host:192.168.122.10
> 2022-08-21 12:39:52,727 INFO [utils.nio.NioClient] (Agent-Handler-3:null)
> (logid:) Connecting to 192.168.122.10:8250
> 2022-08-21 12:39:52,727 WARN [utils.nio.NioConnection]
> (Agent-Handler-3:null) (logid:) Unable to connect to remote: is there a
> server running on port 8250
> 2022-08-21 12:39:57,728 INFO [cloud.agent.Agent] (Agent-Handler-3:null)
> (logid:) Reconnecting to host:192.168.122.10
> 2022-08-21 12:39:57,728 INFO [utils.nio.NioClient] (Agent-Handler-3:null)
> (logid:) Connecting to 192.168.122.10:8250
> 2022-08-21 12:39:57,728 WARN [utils.nio.NioConnection]
> (Agent-Handler-3:null) (logid:) Unable to connect to remote: is there a
> server running on port 8250
> 2022-08-21 12:40:02,729 INFO [cloud.agent.Agent] (Agent-Handler-3:null)
> (logid:) Reconnecting to host:192.168.122.10
> 2022-08-21 12:40:02,729 INFO [utils.nio.NioClient] (Agent-Handler-3:null)
> (logid:) Connecting to 192.168.122.10:8250
> 2022-08-21 12:40:02,729 WARN [utils.nio.NioConnection]
> (Agent-Handler-3:null) (logid:) Unable to connect to remote: is there a
> server running on port 8250
> 2022-08-21 12:40:07,729 INFO [cloud.agent.Agent] (Agent-Handler-3:null)
> (logid:) Reconnecting to host:192.168.122.10
> 2022-08-21 12:40:07,730 INFO [utils.nio.NioClient] (Agent-Handler-3:null)
> (logid:) Connecting to 192.168.122.10:8250
> 2022-08-21 12:40:07,730 WARN [utils.nio.NioConnection]
> (Agent-Handler-3:null) (logid:) Unable to connect to remote: is there a
> server running on port 8250
> 2022-08-21 12:40:09,789 INFO [cloud.agent.Agent]
> (AgentShutdownThread:null) (logid:) Stopping the agent: Reason = sig.kill
> 2022-08-21 12:40:11,109 INFO [cloud.agent.AgentShell] (main:null)
> (logid:) Agent started
> 2022-08-21 12:40:11,111 INFO [cloud.agent.AgentShell] (main:null)
> (logid:) Implementation Version is 4.17.0.1
> 2022-08-21 12:40:11,113 INFO [cloud.agent.AgentShell] (main:null)
> (logid:) agent.properties found at /etc/cloudstack/agent/agent.properties
> 2022-08-21 12:40:11,118 INFO [cloud.agent.AgentShell] (main:null)
> (logid:) Defaulting to using properties file for storage
> 2022-08-21 12:40:11,119 INFO [cloud.agent.AgentShell] (main:null)
> (logid:) Defaulting to the constant time backoff algorithm
> 2022-08-21 12:40:11,128 INFO [cloud.utils.LogUtils] (main:null) (logid:)
> log4j configuration found at /etc/cloudstack/agent/log4j-cloud.xml
> 2022-08-21 12:40:11,129 INFO [cloud.agent.AgentShell] (main:null)
> (logid:) Using default Java settings for IPv6 preference for agent
> connection
> 2022-08-21 12:40:11,183 INFO [cloud.agent.Agent] (main:null) (logid:) id
> is 43
> 2022-08-21 12:40:11,189 ERROR [kvm.resource.LibvirtComputingResource]
> (main:null) (logid:) uefi properties file not found due to: Unable to find
> file uefi.properties.
> 2022-08-21 12:40:11,214 INFO [kvm.resource.LibvirtConnection] (main:null)
> (logid:) No existing libvirtd connection found. Opening a new one
> 2022-08-21 12:40:11,301 INFO [kvm.resource.LibvirtComputingResource]
> (main:null) (logid:) IO uring driver for Qemu: disabled
> 2022-08-21 12:40:11,344 WARN [kvm.storage.KVMStoragePoolManager]
> (main:null) (logid:) Duplicate StorageAdaptor type PowerFlex, not loading
> com.cloud.hypervisor.kvm.storage.ScaleIOStorageAdaptor
> 2022-08-21 12:40:11,345 INFO [kvm.resource.LibvirtComputingResource]
> (main:null) (logid:) No libvirt.vif.driver specified. Defaults to
> BridgeVifDriver.
> 2022-08-21 12:40:11,433 INFO [kvm.resource.LibvirtComputingResource]
> (main:null) (logid:) iscsi session clean up is disabled
> 2022-08-21 12:40:11,440 INFO [cloud.agent.Agent] (main:null) (logid:)
> Agent [id = 43 : type = LibvirtComputingResource : zone = 1 : pod = 1 :
> workers = 5 : host = 192.168.122.10 : port = 8250
> 2022-08-21 12:40:11,446 INFO [utils.nio.NioClient] (main:null) (logid:)
> Connecting to 192.168.122.10:8250
> 2022-08-21 12:40:11,447 WARN [utils.nio.NioConnection] (main:null)
> (logid:) Unable to connect to remote: is there a server running on port 8250
> 2022-08-21 12:40:16,448 INFO [cloud.agent.Agent] (main:null) (logid:)
> Connecting to host:192.168.122.10
> 2022-08-21 12:40:16,449 INFO [utils.nio.NioClient] (main:null) (logid:)
> Connecting to 192.168.122.10:8250
> 2022-08-21 12:40:16,453 INFO [utils.nio.Link] (main:null) (logid:) Conf
> file found: /etc/cloudstack/agent/agent.properties
> 2022-08-21 12:40:16,676 INFO [utils.nio.NioClient] (main:null) (logid:)
> SSL: Handshake done
> 2022-08-21 12:40:16,676 INFO [utils.nio.NioClient] (main:null) (logid:)
> Connected to 192.168.122.10:8250
> 2022-08-21 12:40:16,704 INFO [utils.linux.KVMHostInfo]
> (Agent-Handler-1:null) (logid:) Fetching CPU speed from command "lscpu".
> 2022-08-21 12:40:16,707 INFO [utils.linux.KVMHostInfo]
> (Agent-Handler-1:null) (logid:) Command [lscpu | grep -i 'Model name' |
> head -n 1 | egrep -o '[[:digit:]].[[:digit:]]+GHz' | sed 's/GHz//g']
> resulted in the value [3500] for CPU speed.
> 2022-08-21 12:40:16,731 INFO [kvm.storage.LibvirtStorageAdaptor]
> (Agent-Handler-1:null) (logid:) Attempting to create storage pool
> ead53ee9-2c93-4580-b1a1-a4e1774dd4cf (Filesystem) in libvirt
> 2022-08-21 12:40:16,733 ERROR [kvm.resource.LibvirtConnection]
> (Agent-Handler-1:null) (logid:) Connection with libvirtd is broken: invalid
> connection pointer in virConnectGetVersion
> 2022-08-21 12:40:16,734 INFO [kvm.storage.LibvirtStorageAdaptor]
> (Agent-Handler-1:null) (logid:) Found existing defined storage pool
> ead53ee9-2c93-4580-b1a1-a4e1774dd4cf, using it.
> 2022-08-21 12:40:16,734 INFO [kvm.storage.LibvirtStorageAdaptor]
> (Agent-Handler-1:null) (logid:) Trying to fetch storage pool
> ead53ee9-2c93-4580-b1a1-a4e1774dd4cf from libvirt
> 2022-08-21 12:40:16,762 INFO [cloud.serializer.GsonHelper]
> (Agent-Handler-1:null) (logid:) Default Builder inited.
> 2022-08-21 12:40:16,780 INFO [cloud.agent.Agent] (Agent-Handler-2:null)
> (logid:) Process agent startup answer, agent id = 0
> 2022-08-21 12:40:16,780 INFO [cloud.agent.Agent] (Agent-Handler-2:null)
> (logid:) Set agent id 0
> 2022-08-21 12:40:16,790 INFO [cloud.agent.Agent] (Agent-Handler-2:null)
> (logid:) Startup Response Received: agent id = 0
> 2022-08-21 12:40:17,074 INFO [cloud.agent.Agent]
> (agentRequest-Handler-3:null) (logid:52fd8ef6) Processing agent ready
> command, agent id = 43
> 2022-08-21 12:40:17,075 INFO [cloud.agent.Agent]
> (agentRequest-Handler-3:null) (logid:52fd8ef6) Set agent id 43
> 2022-08-21 12:40:17,077 INFO [cloud.agent.Agent]
> (agentRequest-Handler-3:null) (logid:52fd8ef6) Ready command is processed
> for agent id = 43
> 2022-08-21 12:40:17,098 INFO [cloud.agent.Agent]
> (agentRequest-Handler-4:null) (logid:52fd8ef6) Processing agent ready
> command, agent id = 43
> 2022-08-21 12:40:17,098 INFO [cloud.agent.Agent]
> (agentRequest-Handler-4:null) (logid:52fd8ef6) Set agent id 43
> 2022-08-21 12:40:17,099 INFO [cloud.agent.Agent]
> (agentRequest-Handler-4:null) (logid:52fd8ef6) Processed new management
> server list: 192.168.122.10@static
> 2022-08-21 12:40:17,099 INFO [cloud.agent.Agent]
> (agentRequest-Handler-4:null) (logid:52fd8ef6) Ready command is processed
> for agent id = 43
> 2022-08-21 12:40:27,717 INFO [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-5:null) (logid:380fadc1) Trying to fetch storage pool
> ead53ee9-2c93-4580-b1a1-a4e1774dd4cf from libvirt
> 2022-08-21 12:40:27,727 INFO [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-5:null) (logid:380fadc1) Trying to fetch storage pool
> ead53ee9-2c93-4580-b1a1-a4e1774dd4cf from libvirt
> 2022-08-21 12:40:27,786 INFO [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-3:null) (logid:bf459d7b) Trying to fetch storage pool
> ead53ee9-2c93-4580-b1a1-a4e1774dd4cf from libvirt
> 2022-08-21 12:40:27,788 INFO [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-3:null) (logid:bf459d7b) Asking libvirt to refresh
> storage pool ead53ee9-2c93-4580-b1a1-a4e1774dd4cf
> 2022-08-21 12:41:27,933 INFO [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-1:null) (logid:741b1f7f) Trying to fetch storage pool
> ead53ee9-2c93-4580-b1a1-a4e1774dd4cf from libvirt
> 2022-08-21 12:41:27,960 INFO [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-1:null) (logid:741b1f7f) Asking libvirt to refresh
> storage pool ead53ee9-2c93-4580-b1a1-a4e1774dd4cf
> 2022-08-21 12:42:27,995 INFO [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-5:null) (logid:42d21ba4) Trying to fetch storage pool
> ead53ee9-2c93-4580-b1a1-a4e1774dd4cf from libvirt
> 2022-08-21 12:42:27,996 INFO [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-5:null) (logid:42d21ba4) Asking libvirt to refresh
> storage pool ead53ee9-2c93-4580-b1a1-a4e1774dd4cf
>
management log:
> 2022-08-21 12:40:40,479 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-11:null) (logid:) SeqA 3-1156: Sending Seq 3-1156: {
> Ans: , MgmtId: 279278805472482, via: 3, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
> }
> 2022-08-21 12:40:41,811 DEBUG [o.a.c.h.HAManagerImpl]
> (BackgroundTaskPollManager-2:ctx-ccb282b9) (logid:eba6beab) HA health check
> task is running...
> 2022-08-21 12:40:42,677 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Running Capacity Checker ...
> 2022-08-21 12:40:42,677 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) recalculating system
> capacity
> 2022-08-21 12:40:42,677 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Executing cpu/ram capacity
> update
> 2022-08-21 12:40:42,680 DEBUG [c.c.c.CapacityManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Found 2 VMs on host 43
> 2022-08-21 12:40:42,680 DEBUG [c.c.c.CapacityManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Found 0 VMs are Migrating
> from host 43
> 2022-08-21 12:40:42,681 DEBUG [c.c.c.CapacityManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Found 0 VM, not running on
> host 43
> 2022-08-21 12:40:42,682 DEBUG [c.c.c.CapacityManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) No need to calibrate cpu
> capacity, host:43 usedCpuCore: 2 reservedCpuCore: 0
> 2022-08-21 12:40:42,682 DEBUG [c.c.c.CapacityManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) No need to calibrate cpu
> capacity, host:43 usedCpu: 1000 reservedCpu: 0
> 2022-08-21 12:40:42,682 DEBUG [c.c.c.CapacityManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) No need to calibrate memory
> capacity, host:43 usedMem: (1.50 GB) 1610612736 reservedMem: (0 bytes) 0
> 2022-08-21 12:40:42,701 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Done executing cpu/ram
> capacity update
> 2022-08-21 12:40:42,701 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Executing storage capacity
> update
> 2022-08-21 12:40:42,705 DEBUG [c.c.s.StorageManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Found storage pool
> rs2-local-ead53ee9 of type Filesystem with overprovisioning factor 2
> 2022-08-21 12:40:42,705 DEBUG [c.c.s.StorageManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Total over provisioned
> capacity calculated is 2 * (467.27 GB) 501729951744
> 2022-08-21 12:40:42,705 DEBUG [c.c.s.StorageManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Total over provisioned
> capacity of the pool rs2-local-ead53ee9 id: 2 is (934.54 GB) 1003459903488
> 2022-08-21 12:40:42,716 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (HostReservationReleaseChecker:ctx-6a5a8111) (logid:001123e9) Checking if
> any host reservation can be released ...
> 2022-08-21 12:40:42,719 DEBUG [c.c.s.StorageManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Successfully set Capacity -
> (934.54 GB) 1003459903488 for capacity type - 9 , DataCenterId - 1,
> HostOrPoolId - 2, PodId 1
> 2022-08-21 12:40:42,719 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Done executing storage
> capacity update
> 2022-08-21 12:40:42,719 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Executing capacity updates
> for public ip and Vlans
> 2022-08-21 12:40:42,721 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (HostReservationReleaseChecker:ctx-6a5a8111) (logid:001123e9) Cannot
> release reservation, Found 2 VMs Running on host 43
> 2022-08-21 12:40:42,721 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (HostReservationReleaseChecker:ctx-6a5a8111) (logid:001123e9) Done running
> HostReservationReleaseChecker ...
> 2022-08-21 12:40:42,730 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Done capacity updates for
> public ip and Vlans
> 2022-08-21 12:40:42,730 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Executing capacity updates
> for private ip
> 2022-08-21 12:40:42,733 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Done executing capacity
> updates for private ip
> 2022-08-21 12:40:42,733 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Done recalculating system
> capacity
> 2022-08-21 12:40:42,756 DEBUG [c.c.a.AlertManagerImpl]
> (CapacityChecker:ctx-d24c52a6) (logid:e0f0fd30) Done running Capacity
> Checker ...
> 2022-08-21 12:40:42,772 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:ctx-d6744278) (logid:4e91ddad) Found 0 routers to
> update status.
> 2022-08-21 12:40:42,772 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:ctx-d6744278) (logid:4e91ddad) Found 0 VPC's to
> update Redundant State.
> 2022-08-21 12:40:42,774 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:ctx-d6744278) (logid:4e91ddad) Found 0 networks to
> update RvR status.
> 2022-08-21 12:40:45,813 DEBUG [o.a.c.h.HAManagerImpl]
> (BackgroundTaskPollManager-2:ctx-918baae8) (logid:bd6a1c85) HA health check
> task is running...
> 2022-08-21 12:40:46,087 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-10:null) (logid:) SeqA 44-976: Processing Seq 44-976:
> { Cmd , MgmtId: -1, via: 44, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"1014","_loadInfo":"{
> "connections": []
> }","wait":"0","bypassHostMaintenance":"false"}}] }
> 2022-08-21 12:40:46,112 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-10:null) (logid:) SeqA 44-976: Sending Seq 44-976: {
> Ans: , MgmtId: 279278805472482, via: 44, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
> }
> 2022-08-21 12:40:49,816 DEBUG [o.a.c.h.HAManagerImpl]
> (BackgroundTaskPollManager-2:ctx-e0670d0f) (logid:86c83e35) HA health check
> task is running...
> 2022-08-21 12:40:50,435 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-9:null) (logid:) SeqA 3-1157: Processing Seq 3-1157:
> { Cmd , MgmtId: -1, via: 3, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"1012","_loadInfo":"{
> "connections": []
> }","wait":"0","bypassHostMaintenance":"false"}}] }
> 2022-08-21 12:40:50,440 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-9:null) (logid:) SeqA 3-1157: Sending Seq 3-1157: {
> Ans: , MgmtId: 279278805472482, via: 3, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
> }
> 2022-08-21 12:40:53,818 DEBUG [o.a.c.h.HAManagerImpl]
> (BackgroundTaskPollManager-2:ctx-26239a45) (logid:468c8842) HA health check
> task is running...
> 2022-08-21 12:40:55,436 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-12:null) (logid:) SeqA 3-1158: Processing Seq 3-1158:
> { Cmd , MgmtId: -1, via: 3, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"1012","_loadInfo":"{
> "connections": []
> }","wait":"0","bypassHostMaintenance":"false"}}] }
> 2022-08-21 12:40:55,440 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-12:null) (logid:) SeqA 3-1158: Sending Seq 3-1158: {
> Ans: , MgmtId: 279278805472482, via: 3, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
> }
> 2022-08-21 12:40:56,130 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-13:null) (logid:) SeqA 44-977: Processing Seq 44-977:
> { Cmd , MgmtId: -1, via: 44, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"1014","_loadInfo":"{
> "connections": []
> }","wait":"0","bypassHostMaintenance":"false"}}] }
> 2022-08-21 12:40:56,158 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-13:null) (logid:) SeqA 44-977: Sending Seq 44-977: {
> Ans: , MgmtId: 279278805472482, via: 44, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
> }
> 2022-08-21 12:40:57,819 DEBUG [o.a.c.h.HAManagerImpl]
> (BackgroundTaskPollManager-6:ctx-65849b01) (logid:9cebee6e) HA health check
> task is running...
> 2022-08-21 12:40:57,992 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-18:ctx-840da5fe) (logid:d547c73f) ===START=== 91.17.169.4
> -- POST command=deployVirtualMachine&response=json
> 2022-08-21 12:40:57,998 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:40:58,019 DEBUG [c.c.u.AccountManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Access
> granted to Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}
> to
> org.apache.cloudstack.quota.vo.ServiceOfferingVO$$EnhancerByCGLIB$$cb3e1f58@10ed8041
> by AffinityGroupAccessChecker
> 2022-08-21 12:40:58,020 DEBUG [c.c.u.AccountManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Access
> granted to Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}
> to com.cloud.storage.DiskOfferingVO$$EnhancerByCGLIB$$74079c4b@450a1ffe
> by AffinityGroupAccessChecker
> 2022-08-21 12:40:58,028 DEBUG [c.c.n.NetworkModelImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Service
> SecurityGroup is not supported in the network id=204
> 2022-08-21 12:40:58,045 INFO [c.c.v.UserVmManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) VM cannot be
> configured to be dynamically scalable if any of the service offering's
> dynamic scaling property, template's dynamic scaling property or global
> setting is false
> 2022-08-21 12:40:58,047 DEBUG [c.c.v.UserVmManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Rootdisksize
> override validation successful. Template root disk size (8.00 GB)
> 8589934592 Root disk size specified 20 GB
> 2022-08-21 12:40:58,052 DEBUG [c.c.v.UserVmManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Allocating in
> the DB for vm
> 2022-08-21 12:40:58,067 INFO [c.c.v.VirtualMachineManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) allocating
> virtual machine from template:df14333f-d421-4923-8ed5-e94f31d3333c with
> hostname:i-2-1017-VM and 1 networks
> 2022-08-21 12:40:58,068 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Allocating
> entries for VM: VM instance {id: "1017", name: "i-2-1017-VM", uuid:
> "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"}
> 2022-08-21 12:40:58,070 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Allocating
> nics for VM instance {id: "1017", name: "i-2-1017-VM", uuid:
> "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"}
> 2022-08-21 12:40:58,078 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Allocating
> nic for vm VM instance {id: "1017", name: "i-2-1017-VM", uuid:
> "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"} in network Network
> {"id": 204, "name": "PhysicalNetwork", "uuid":
> "7d9ec853-73f7-4409-b5b2-24885b624af1", "networkofferingid": 9} with
> requested profile NicProfile
> {"broadcastUri":null,"iPv4Address":null,"id":0,"reservationId":null,"vmId":0}
> 2022-08-21 12:40:58,100 DEBUG [c.c.n.NetworkModelImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Service
> SecurityGroup is not supported in the network id=204
> 2022-08-21 12:40:58,102 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Allocating
> disks for VM instance {id: "1017", name: "i-2-1017-VM", uuid:
> "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"}
> 2022-08-21 12:40:58,102 INFO [o.a.c.e.o.VolumeOrchestrator]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) adding disk
> object ROOT-1017 to i-2-1017-VM
> 2022-08-21 12:40:58,103 DEBUG [o.a.c.e.o.VolumeOrchestrator]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Using root
> disk size of (20.00 GB) 21474836480 Bytes for volume ROOT-1017
> 2022-08-21 12:40:58,108 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Updating
> resource Type = volume count for Account = 2 Operation = increasing Amount
> = 1
> 2022-08-21 12:40:58,112 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Updating
> resource Type = primary_storage count for Account = 2 Operation =
> increasing Amount = (20.00 GB) 21474836480
> 2022-08-21 12:40:58,117 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Updating
> resource Type = volume count for Account = 2 Operation = increasing Amount
> = 1
> 2022-08-21 12:40:58,118 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Updating
> resource Type = primary_storage count for Account = 2 Operation =
> increasing Amount = (20.00 GB) 21474836480
> 2022-08-21 12:40:58,120 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Allocation
> completed for VM: VM instance {id: "1017", name: "i-2-1017-VM", uuid:
> "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"}
> 2022-08-21 12:40:58,120 DEBUG [c.c.v.UserVmManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Successfully
> allocated DB entry for VM instance {id: "1017", name: "i-2-1017-VM", uuid:
> "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"}
> 2022-08-21 12:40:58,121 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Updating
> resource Type = user_vm count for Account = 2 Operation = increasing Amount
> = 1
> 2022-08-21 12:40:58,123 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Updating
> resource Type = cpu count for Account = 2 Operation = increasing Amount = 3
> 2022-08-21 12:40:58,124 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Updating
> resource Type = memory count for Account = 2 Operation = increasing Amount
> = 2048
> 2022-08-21 12:40:58,143 DEBUG [c.c.n.NetworkModelImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Service
> SecurityGroup is not supported in the network id=204
> 2022-08-21 12:40:58,145 DEBUG [c.c.n.NetworkModelImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) Service
> SecurityGroup is not supported in the network id=204
> 2022-08-21 12:40:58,176 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084) (logid:1a0b88df) Add job-3084
> into job monitoring
> 2022-08-21 12:40:58,178 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) submit async
> job-3084, details: AsyncJobVO: {id:3084, userId: 2, accountId: 2,
> instanceType: VirtualMachine, instanceId: 1017, cmd:
> org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin, cmdInfo:
> {"iptonetworklist[0].networkid":"7d9ec853-73f7-4409-b5b2-24885b624af1","hostid":"a3c2ef7e-d639-4dba-b727-e7bd0c371e4c","httpmethod":"POST","ctxAccountId":"2","uuid":"023b3e97-3d91-4f12-9273-eb19d52a1af7","cmdEventType":"VM.CREATE","diskofferingid":"084f0f56-ee9d-4a88-b13e-b60994ad559a","bootmode":"LEGACY","rootdisksize":"20","ctxStartEventId":"1176","id":"1017","overridediskofferingid":"084f0f56-ee9d-4a88-b13e-b60994ad559a","ctxDetails":"{\"interface
> com.cloud.dc.DataCenter\":\"52445840-7fcc-4d72-8220-c4434688b90b\",\"interface
> com.cloud.vm.VirtualMachine\":\"023b3e97-3d91-4f12-9273-eb19d52a1af7\",\"interface
> com.cloud.org.Cluster\":\"b6ed910d-6719-4c03-af5a-8ee97d67c3eb\",\"interface
> com.cloud.offering.ServiceOffering\":\"5e91fc51-a2ef-4d6b-b9d1-037fed808f7e\",\"interface
> com.cloud.host.Host\":\"a3c2ef7e-d639-4dba-b727-e7bd0c371e4c\",\"interface
> com.cloud.offering.DiskOffering\":\"084f0f56-ee9d-4a88-b13e-b60994ad559a\",\"interface
> com.cloud.template.VirtualMachineTemplate\":\"df14333f-d421-4923-8ed5-e94f31d3333c\",\"interface
> com.cloud.dc.Pod\":\"4fd7e416-a226-46b5-b04d-593d53a3cbf3\"}","keypairs":"","boottype":"BIOS","clusterid":"b6ed910d-6719-4c03-af5a-8ee97d67c3eb","templateid":"df14333f-d421-4923-8ed5-e94f31d3333c","startvm":"true","serviceofferingid":"5e91fc51-a2ef-4d6b-b9d1-037fed808f7e","response":"json","ctxUserId":"2","displayname":"VM3","name":"VM3","zoneid":"52445840-7fcc-4d72-8220-c4434688b90b","podid":"4fd7e416-a226-46b5-b04d-593d53a3cbf3","affinitygroupids":""},
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 279278805472482, completeMsid: null, lastUpdated:
> null, lastPolled: null, created: null, removed: null}
> 2022-08-21 12:40:58,178 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-18:ctx-840da5fe ctx-b9d9f13b) (logid:d547c73f) ===END===
> 91.17.169.4 -- POST command=deployVirtualMachine&response=json
> 2022-08-21 12:40:58,178 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084) (logid:26f88def) Executing
> AsyncJobVO: {id:3084, userId: 2, accountId: 2, instanceType:
> VirtualMachine, instanceId: 1017, cmd:
> org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin, cmdInfo:
> {"iptonetworklist[0].networkid":"7d9ec853-73f7-4409-b5b2-24885b624af1","hostid":"a3c2ef7e-d639-4dba-b727-e7bd0c371e4c","httpmethod":"POST","ctxAccountId":"2","uuid":"023b3e97-3d91-4f12-9273-eb19d52a1af7","cmdEventType":"VM.CREATE","diskofferingid":"084f0f56-ee9d-4a88-b13e-b60994ad559a","bootmode":"LEGACY","rootdisksize":"20","ctxStartEventId":"1176","id":"1017","overridediskofferingid":"084f0f56-ee9d-4a88-b13e-b60994ad559a","ctxDetails":"{\"interface
> com.cloud.dc.DataCenter\":\"52445840-7fcc-4d72-8220-c4434688b90b\",\"interface
> com.cloud.vm.VirtualMachine\":\"023b3e97-3d91-4f12-9273-eb19d52a1af7\",\"interface
> com.cloud.org.Cluster\":\"b6ed910d-6719-4c03-af5a-8ee97d67c3eb\",\"interface
> com.cloud.offering.ServiceOffering\":\"5e91fc51-a2ef-4d6b-b9d1-037fed808f7e\",\"interface
> com.cloud.host.Host\":\"a3c2ef7e-d639-4dba-b727-e7bd0c371e4c\",\"interface
> com.cloud.offering.DiskOffering\":\"084f0f56-ee9d-4a88-b13e-b60994ad559a\",\"interface
> com.cloud.template.VirtualMachineTemplate\":\"df14333f-d421-4923-8ed5-e94f31d3333c\",\"interface
> com.cloud.dc.Pod\":\"4fd7e416-a226-46b5-b04d-593d53a3cbf3\"}","keypairs":"","boottype":"BIOS","clusterid":"b6ed910d-6719-4c03-af5a-8ee97d67c3eb","templateid":"df14333f-d421-4923-8ed5-e94f31d3333c","startvm":"true","serviceofferingid":"5e91fc51-a2ef-4d6b-b9d1-037fed808f7e","response":"json","ctxUserId":"2","displayname":"VM3","name":"VM3","zoneid":"52445840-7fcc-4d72-8220-c4434688b90b","podid":"4fd7e416-a226-46b5-b04d-593d53a3cbf3","affinitygroupids":""},
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 279278805472482, completeMsid: null, lastUpdated:
> null, lastPolled: null, created: null, removed: null}
> 2022-08-21 12:40:58,205 DEBUG [c.c.n.NetworkModelImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Service SecurityGroup is not supported in the network id=204
> 2022-08-21 12:40:58,206 DEBUG [c.c.n.NetworkModelImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Service SecurityGroup is not supported in the network id=204
> 2022-08-21 12:40:58,207 DEBUG [c.c.v.UserVmManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Destination Host to deploy the VM is specified, specifying a deployment
> plan to deploy the VM
> 2022-08-21 12:40:58,212 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Host: 43 has cpu capability (cpu:12, speed:3500) to support requested CPU:
> 3 and requested speed: 1500
> 2022-08-21 12:40:58,213 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Checking if host: 43 has enough capacity for requested CPU: 4500 and
> requested RAM: (2.00 GB) 2147483648 , cpuOverprovisioningFactor: 1.0
> 2022-08-21 12:40:58,214 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Hosts's actual total CPU: 42000 and CPU after applying overprovisioning:
> 42000
> 2022-08-21 12:40:58,214 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> considerReservedCapacity isfalse , not considering reserved capacity for
> calculating free capacity
> 2022-08-21 12:40:58,214 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Free CPU: 41000 , Requested CPU: 4500
> 2022-08-21 12:40:58,214 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Free RAM: (60.20 GB) 64640737280 , Requested RAM: (2.00 GB) 2147483648
> 2022-08-21 12:40:58,214 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Host has enough CPU and RAM available
> 2022-08-21 12:40:58,218 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> STATS: Can alloc CPU from host: 43, used: 1000, reserved: 0, actual total:
> 42000, total with overprovisioning: 42000; requested
> cpu:4500,alloc_from_last_host?:false ,considerReservedCapacity?: false
> 2022-08-21 12:40:58,222 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-23:ctx-195ede7b) (logid:97536160) ===START=== 91.17.169.4
> -- GET
>
> jobId=26f88def-aec9-40b1-b432-c6a81d0326d4&command=queryAsyncJobResult&response=json
> 2022-08-21 12:40:58,222 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> STATS: Can alloc MEM from host: 43, used: (1.50 GB) 1610612736, reserved:
> (0 bytes) 0, total: (61.70 GB) 66251350016; requested mem: (2.00 GB)
> 2147483648, alloc_from_last_host?: false , considerReservedCapacity?: false
> 2022-08-21 12:40:58,225 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-23:ctx-195ede7b ctx-e93b8eb4) (logid:97536160) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:40:58,234 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Adding pods to avoid lists for non-explicit VM deployment: []
> 2022-08-21 12:40:58,234 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Adding clusters to avoid lists for non-explicit VM deployment: []
> 2022-08-21 12:40:58,234 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Adding hosts to avoid lists for non-explicit VM deployment: []
> 2022-08-21 12:40:58,234 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> DeploymentPlanner allocation algorithm: null
> 2022-08-21 12:40:58,237 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1,
> requested cpu: 4500, requested ram: (2.00 GB) 2147483648
> 2022-08-21 12:40:58,237 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def) Is
> ROOT volume READY (pool already allocated)?: No
> 2022-08-21 12:40:58,240 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> DeploymentPlan has host_id specified, choosing this host and making no
> checks on this host: 43
> 2022-08-21 12:40:58,241 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Looking for suitable pools for this host under zone: 1, pod: 1, cluster: 1
> 2022-08-21 12:40:58,243 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Checking suitable pools for volume (Id, Type): (1020,ROOT)
> 2022-08-21 12:40:58,243 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def) We
> need to allocate new storagepool for this volume
> 2022-08-21 12:40:58,244 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Calling StoragePoolAllocators to find suitable pools
> 2022-08-21 12:40:58,245 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> LocalStoragePoolAllocator trying to find storage pool to fit the vm
> 2022-08-21 12:40:58,245 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-23:ctx-195ede7b ctx-e93b8eb4) (logid:97536160) ===END===
> 91.17.169.4 -- GET
>
> jobId=26f88def-aec9-40b1-b432-c6a81d0326d4&command=queryAsyncJobResult&response=json
> 2022-08-21 12:40:58,246 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> LocalStoragePoolAllocator returning 0 suitable storage pools
> 2022-08-21 12:40:58,246 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> ClusterScopeStoragePoolAllocator looking for storage pool
> 2022-08-21 12:40:58,246 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> ZoneWideStoragePoolAllocator to find storage pool
> 2022-08-21 12:40:58,246 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def) No
> suitable pools found for volume: Vol[1020|vm=1017|ROOT] under cluster: 1
> 2022-08-21 12:40:58,246 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def) No
> suitable pools found
> 2022-08-21 12:40:58,246 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Cannot deploy to specified host, returning.
> 2022-08-21 12:40:58,247 DEBUG [c.c.v.UserVmManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Destroying vm VM instance {id: "1017", name: "i-2-1017-VM", uuid:
> "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"} as it failed to create
> on Host with Id:43
> 2022-08-21 12:40:58,263 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def) VM
> instance {id: "1017", name: "i-2-1017-VM", uuid:
> "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"} state transited from
> [Stopped] to [Error] with event [OperationFailedToError]. VM's original
> host: null, new host: null, host before state transition: null
> 2022-08-21 12:40:58,304 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Updating resource Type = volume count for Account = 2 Operation =
> decreasing Amount = 1
> 2022-08-21 12:40:58,317 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Updating resource Type = primary_storage count for Account = 2 Operation =
> decreasing Amount = (20.00 GB) 21474836480
> 2022-08-21 12:40:58,377 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Updating resource Type = volume count for Account = 2 Operation =
> decreasing Amount = 1
> 2022-08-21 12:40:58,398 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Updating resource Type = primary_storage count for Account = 2 Operation =
> decreasing Amount = (20.00 GB) 21474836480
> 2022-08-21 12:40:58,438 WARN [c.c.a.AlertManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> alertType=[8] dataCenterId=[1] podId=[null] clusterId=[null]
> message=[Failed to deploy Vm with Id: 1017, on Host with Id: 43].
> 2022-08-21 12:40:58,465 WARN [c.c.a.AlertManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def) No
> recipients set in global setting 'alert.email.addresses', skipping sending
> alert with subject [Failed to deploy Vm with Id: 1017, on Host with Id: 43]
> and content [Failed to deploy Vm with Id: 1017, on Host with Id: 43].
> 2022-08-21 12:40:58,469 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Updating resource Type = user_vm count for Account = 2 Operation =
> decreasing Amount = 1
> 2022-08-21 12:40:58,499 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Updating resource Type = cpu count for Account = 2 Operation = decreasing
> Amount = 3
> 2022-08-21 12:40:58,524 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-18:ctx-5f1cb1b7) (logid:e58e0869) ===START=== 91.17.169.4
> -- GET
>
> resourceids=df14333f-d421-4923-8ed5-e94f31d3333c&resourcetype=template&command=listResourceIcon&response=json
> 2022-08-21 12:40:58,524 DEBUG [c.c.r.ResourceLimitManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> Updating resource Type = memory count for Account = 2 Operation =
> decreasing Amount = 2048
> 2022-08-21 12:40:58,537 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-18:ctx-5f1cb1b7 ctx-cdd3aa57) (logid:e58e0869) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:40:58,537 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-318:ctx-7b55fd93) (logid:e677287e) ===START=== 91.17.169.4
> -- GET showicon=true&command=listZones&response=json
> 2022-08-21 12:40:58,537 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-19:ctx-0185cd56) (logid:12d01e11) ===START=== 91.17.169.4
> -- GET command=listZones&response=json
> 2022-08-21 12:40:58,538 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-316:ctx-f1be54e5) (logid:7c6900fd) ===START=== 91.17.169.4
> -- GET page=1&pagesize=6&listall=true&command=listEvents&response=json
> 2022-08-21 12:40:58,539 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-318:ctx-7b55fd93 ctx-a319ae48) (logid:e677287e) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:40:58,539 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-18:ctx-5f1cb1b7 ctx-cdd3aa57) (logid:e58e0869) ===END===
> 91.17.169.4 -- GET
>
> resourceids=df14333f-d421-4923-8ed5-e94f31d3333c&resourcetype=template&command=listResourceIcon&response=json
> 2022-08-21 12:40:58,539 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-19:ctx-0185cd56 ctx-2945cfcd) (logid:12d01e11) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:40:58,540 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-316:ctx-f1be54e5 ctx-2721e44f) (logid:7c6900fd) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:40:58,542 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-19:ctx-0185cd56 ctx-2945cfcd) (logid:12d01e11) ===END===
> 91.17.169.4 -- GET command=listZones&response=json
> 2022-08-21 12:40:58,543 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-318:ctx-7b55fd93 ctx-a319ae48) (logid:e677287e) ===END===
> 91.17.169.4 -- GET showicon=true&command=listZones&response=json
> 2022-08-21 12:40:58,562 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-24:ctx-d74c3c28) (logid:3ce909ce) ===START=== 91.17.169.4
> -- GET
>
> resourceids=52445840-7fcc-4d72-8220-c4434688b90b&resourcetype=zone&command=listResourceIcon&response=json
> 2022-08-21 12:40:58,565 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-24:ctx-d74c3c28 ctx-6fa0d9d3) (logid:3ce909ce) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:40:58,567 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-24:ctx-d74c3c28 ctx-6fa0d9d3) (logid:3ce909ce) ===END===
> 91.17.169.4 -- GET
>
> resourceids=52445840-7fcc-4d72-8220-c4434688b90b&resourcetype=zone&command=listResourceIcon&response=json
> 2022-08-21 12:40:58,573 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-319:ctx-ecb46bf3) (logid:a5659fd0) ===START=== 91.17.169.4
> -- GET
>
> zoneid=52445840-7fcc-4d72-8220-c4434688b90b&fetchlatest=false&command=listCapacity&response=json
> 2022-08-21 12:40:58,576 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-319:ctx-ecb46bf3 ctx-ac53f298) (logid:a5659fd0) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:40:58,577 INFO [o.a.c.a.c.u.v.DeployVMCmd]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def)
> com.cloud.exception.InsufficientServerCapacityException: No destination
> found for a deployment for VM instance {id: "1017", name: "i-2-1017-VM",
> uuid: "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"}Scope=interface
> com.cloud.dc.DataCenter; id=1
> 2022-08-21 12:40:58,577 INFO [o.a.c.a.c.u.v.DeployVMCmd]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084 ctx-562f9fba) (logid:26f88def) No
> destination found for a deployment for VM instance {id: "1017", name:
> "i-2-1017-VM", uuid: "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"}
> com.cloud.exception.InsufficientServerCapacityException: No destination
> found for a deployment for VM instance {id: "1017", name: "i-2-1017-VM",
> uuid: "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"}Scope=interface
> com.cloud.dc.DataCenter; id=1
> at
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:225)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:202)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:5280)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:5131)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4758)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4747)
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
> Method)
> at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at
> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
> 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:175)
> at
> com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:52)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
> at
> org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
> at
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
> at com.sun.proxy.$Proxy128.startVirtualMachine(Unknown Source)
> at
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:714)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:163)
> at
> com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:106)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
> at
> java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> at java.base/java.lang.Thread.run(Thread.java:829)
> 2022-08-21 12:40:58,583 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-316:ctx-f1be54e5 ctx-2721e44f) (logid:7c6900fd) ===END===
> 91.17.169.4 -- GET
> page=1&pagesize=6&listall=true&command=listEvents&response=json
> 2022-08-21 12:40:58,584 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084) (logid:26f88def) Complete async
> job-3084, jobStatus: FAILED, resultCode: 530, result:
> org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":"533","errortext":"No
> destination found for a deployment for VM instance {id: "1017", name:
> "i-2-1017-VM", uuid: "023b3e97-3d91-4f12-9273-eb19d52a1af7", type="User"}"}
> 2022-08-21 12:40:58,585 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084) (logid:26f88def) Publish async
> job-3084 complete on message bus
> 2022-08-21 12:40:58,585 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084) (logid:26f88def) Wake up jobs
> related to job-3084
> 2022-08-21 12:40:58,585 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084) (logid:26f88def) Update db
> status for job-3084
> 2022-08-21 12:40:58,585 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084) (logid:26f88def) Wake up jobs
> joined with job-3084 and disjoin all subjobs created from job- 3084
> 2022-08-21 12:40:58,586 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-319:ctx-ecb46bf3 ctx-ac53f298) (logid:a5659fd0) ===END===
> 91.17.169.4 -- GET
>
> zoneid=52445840-7fcc-4d72-8220-c4434688b90b&fetchlatest=false&command=listCapacity&response=json
> 2022-08-21 12:40:58,604 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084) (logid:26f88def) Done executing
> org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin for job-3084
> 2022-08-21 12:40:58,605 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (API-Job-Executor-1:ctx-6f90dd7b job-3084) (logid:26f88def) Remove job-3084
> from job monitoring
> 2022-08-21 12:41:01,339 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-17:ctx-b144e321) (logid:d93226dc) ===START=== 91.17.169.4
> -- GET
>
> jobId=26f88def-aec9-40b1-b432-c6a81d0326d4&command=queryAsyncJobResult&response=json
> 2022-08-21 12:41:01,345 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-17:ctx-b144e321 ctx-e7cc3a93) (logid:d93226dc) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:41:01,373 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-17:ctx-b144e321 ctx-e7cc3a93) (logid:d93226dc) ===END===
> 91.17.169.4 -- GET
>
> jobId=26f88def-aec9-40b1-b432-c6a81d0326d4&command=queryAsyncJobResult&response=json
> 2022-08-21 12:41:01,822 DEBUG [o.a.c.h.HAManagerImpl]
> (BackgroundTaskPollManager-6:ctx-dffb6c02) (logid:05bfcf84) HA health check
> task is running...
> 2022-08-21 12:41:05,481 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-14:null) (logid:) SeqA 3-1159: Processing Seq 3-1159:
> { Cmd , MgmtId: -1, via: 3, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"1012","_loadInfo":"{
> "connections": []
> }","wait":"0","bypassHostMaintenance":"false"}}] }
> 2022-08-21 12:41:05,483 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-14:null) (logid:) SeqA 3-1159: Sending Seq 3-1159: {
> Ans: , MgmtId: 279278805472482, via: 3, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
> }
> 2022-08-21 12:41:05,824 DEBUG [o.a.c.h.HAManagerImpl]
> (BackgroundTaskPollManager-6:ctx-ff6e8ea9) (logid:0bc42cb3) HA health check
> task is running...
> 2022-08-21 12:41:06,088 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-15:null) (logid:) SeqA 44-978: Processing Seq 44-978:
> { Cmd , MgmtId: -1, via: 44, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"1014","_loadInfo":"{
> "connections": []
> }","wait":"0","bypassHostMaintenance":"false"}}] }
> 2022-08-21 12:41:06,111 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-15:null) (logid:) SeqA 44-978: Sending Seq 44-978: {
> Ans: , MgmtId: 279278805472482, via: 44, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
> }
> 2022-08-21 12:41:08,959 DEBUG [c.c.s.StatsCollector]
> (secstorage-1:ctx-d808f4f6) (logid:97a63427) Verifying image storage [1].
> Capacity: total=[467 GB], used=[20 GB], threshold=[89.99999761581421%].
> 2022-08-21 12:41:08,961 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-d808f4f6) (logid:97a63427) Zone [1] is ready to launch
> secondary storage VM.
> 2022-08-21 12:41:09,088 DEBUG [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-8cc9edab) (logid:0b501e1f) Zone 1 is ready to launch
> console proxy
> 2022-08-21 12:41:09,825 DEBUG [o.a.c.h.HAManagerImpl]
> (BackgroundTaskPollManager-6:ctx-530f998c) (logid:a2360ea5) HA health check
> task is running...
> 2022-08-21 12:41:11,090 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-4:null) (logid:) SeqA 44-979: Processing Seq 44-979:
> { Cmd , MgmtId: -1, via: 44, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"1014","_loadInfo":"{
> "connections": []
> }","wait":"0","bypassHostMaintenance":"false"}}] }
> 2022-08-21 12:41:11,115 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-4:null) (logid:) SeqA 44-979: Sending Seq 44-979: {
> Ans: , MgmtId: 279278805472482, via: 44, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
> }
> 2022-08-21 12:41:12,686 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-5:ctx-e6b11663) (logid:1772f3fe) DbCollector is running...
> 2022-08-21 12:41:12,773 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:ctx-3ff1c604) (logid:f6ac28c2) Found 0 routers to
> update status.
> 2022-08-21 12:41:12,774 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:ctx-3ff1c604) (logid:f6ac28c2) Found 0 VPC's to
> update Redundant State.
> 2022-08-21 12:41:12,776 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:ctx-3ff1c604) (logid:f6ac28c2) Found 0 networks to
> update RvR status.
> 2022-08-21 12:41:13,363 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-1:null) (logid:) Ping from 45(s-1013-VM)
> 2022-08-21 12:41:13,363 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-7:null) (logid:) Ping from 3(v-1012-VM)
> 2022-08-21 12:41:13,363 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-2:null) (logid:) Ping from 4(s-1011-VM)
> 2022-08-21 12:41:13,414 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-3:null) (logid:) Ping from 44(v-1014-VM)
> 2022-08-21 12:41:13,686 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) ManagementServerCollector
> is running...
> 2022-08-21 12:41:13,688 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c
> systemctl status cloudstack-usage | grep " Loaded:"
> 2022-08-21 12:41:13,689 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,700 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,703 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) usage install: Loaded:
> loaded (/lib/systemd/system/cloudstack-usage.service; enabled; vendor
> preset: enabled)
> 2022-08-21 12:41:13,703 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Sessions active: 1
> 2022-08-21 12:41:13,704 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c
> cat /etc/os-release | grep PRETTY_NAME | cut -f2 -d '=' | tr -d '"'
> 2022-08-21 12:41:13,705 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,710 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,713 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c
> uname -r
> 2022-08-21 12:41:13,713 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,716 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,717 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c
> cat /proc/meminfo | grep MemTotal | cut -f 2 -d ':' | tr -d 'a-zA-z '
> 2022-08-21 12:41:13,718 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,723 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,724 INFO [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) system memory from /proc:
> 67325091840
> 2022-08-21 12:41:13,724 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c
> cat /proc/meminfo | grep MemFree | cut -f 2 -d ':' | tr -d 'a-zA-z '
> 2022-08-21 12:41:13,724 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,729 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,730 INFO [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) free memory from /proc:
> 56703590400
> 2022-08-21 12:41:13,730 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c ps
> -o rss= 529486
> 2022-08-21 12:41:13,731 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,743 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,743 INFO [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) used memory from /proc:
> 1156256
> 2022-08-21 12:41:13,744 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c
> uptime -s
> 2022-08-21 12:41:13,744 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,746 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,746 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c ps
> -o vsz= 529486
> 2022-08-21 12:41:13,747 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,754 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,754 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c
> cat /proc/cpuinfo | grep "cpu MHz" | grep "cpu MHz" | cut -f 2 -d : | tr -d
> ' '| tr '\n' " "
> 2022-08-21 12:41:13,754 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,775 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,776 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c
> cat /proc/loadavg
> 2022-08-21 12:41:13,777 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,780 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,781 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c
> cat /proc/stat | grep "cpu " | tr -d "cpu"
> 2022-08-21 12:41:13,781 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,786 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,787 DEBUG [c.c.u.LogUtils]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) file for FILE :
> /var/log/cloudstack/management/management-server.log
> 2022-08-21 12:41:13,787 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c du
> -sh /var/log/cloudstack/management/management-server.log | cut -f '1'
> 2022-08-21 12:41:13,788 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,792 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,793 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing: /bin/bash -c df
> -h /var/log/cloudstack/management/management-server.log | grep -v
> Filesystem | awk '{print "on disk " $1 " mounted on " $6 " (" $5 " full)"}'
> 2022-08-21 12:41:13,794 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Executing while with
> timeout : 3600000
> 2022-08-21 12:41:13,799 DEBUG [c.c.u.s.Script]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Execution is successful.
> 2022-08-21 12:41:13,803 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> buffersdirect.capacity, 174557
> 2022-08-21 12:41:13,803 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> buffersdirect.count, 29
> 2022-08-21 12:41:13,803 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> buffersdirect.used, 174557
> 2022-08-21 12:41:13,803 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> buffersmapped.capacity, 0
> 2022-08-21 12:41:13,803 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> buffersmapped.count, 0
> 2022-08-21 12:41:13,803 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> buffersmapped.used, 0
> 2022-08-21 12:41:13,803 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> gcPS-MarkSweep.count, 4
> 2022-08-21 12:41:13,803 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> gcPS-MarkSweep.time, 296
> 2022-08-21 12:41:13,803 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> gcPS-Scavenge.count, 24
> 2022-08-21 12:41:13,804 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> gcPS-Scavenge.time, 110
> 2022-08-21 12:41:13,804 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> jvmname, 529486@rs2
> 2022-08-21 12:41:13,804 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> jvmuptime, 73913
> 2022-08-21 12:41:13,804 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> jvmvendor, Ubuntu OpenJDK 64-Bit Server VM
> 11.0.16+8-post-Ubuntu-0ubuntu120.04 (11)
> 2022-08-21 12:41:13,804 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memoryheap.committed, 1216872448
> 2022-08-21 12:41:13,804 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memoryheap.init, 1052770304
> 2022-08-21 12:41:13,804 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memoryheap.usage, 0.19627511962957678
> 2022-08-21 12:41:13,804 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorynon-heap.committed, 179879936
> 2022-08-21 12:41:13,804 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorynon-heap.init, 7667712
> 2022-08-21 12:41:13,805 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorynon-heap.max, -1
> 2022-08-21 12:41:13,805 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorynon-heap.usage, -1.72181496E8
> 2022-08-21 12:41:13,805 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorynon-heap.used, 172181496
> 2022-08-21 12:41:13,805 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorypools.CodeHeap-'non-nmethods'.usage, 0.3161184210526316
> 2022-08-21 12:41:13,805 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorypools.CodeHeap-'non-profiled-nmethods'.usage, 0.12420542022127433
> 2022-08-21 12:41:13,805 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorypools.CodeHeap-'profiled-nmethods'.usage, 0.22857999800046655
> 2022-08-21 12:41:13,805 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorypools.Compressed-Class-Space.usage, 0.01073785126209259
> 2022-08-21 12:41:13,805 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorypools.Metaspace.usage, 0.9728361785732776
> 2022-08-21 12:41:13,805 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorypools.PS-Eden-Space.usage, 0.35541527820890295
> 2022-08-21 12:41:13,805 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorypools.PS-Old-Gen.usage, 0.08758915356776079
> 2022-08-21 12:41:13,806 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorypools.PS-Survivor-Space.usage, 0.8463897705078125
> 2022-08-21 12:41:13,806 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorytotal.committed, 1396752384
> 2022-08-21 12:41:13,806 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorytotal.init, 1060438016
> 2022-08-21 12:41:13,806 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorytotal.max, 1908932607
> 2022-08-21 12:41:13,806 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> memorytotal.used, 547400624
> 2022-08-21 12:41:13,807 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> threadsdeadlocks, []
> 2022-08-21 12:41:13,808 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> threadsnew.count, 0
> 2022-08-21 12:41:13,810 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) not storing detail
> threadstimed_waiting.count, 84
> 2022-08-21 12:41:13,816 DEBUG [c.c.c.ClusterManagerImpl]
> (StatsCollector-6:ctx-6d42adbd) (logid:d2adf91d) Forwarding
> {"managementServerHostId":3,"managementServerHostUuid":"7f5d510c-b780-4d98-91ec-ce43c8a673d2","collectionTime":"Aug
> 21, 2022, 12:41:13
> PM","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":1216872448,"freeJvmMemoryBytes":842738392,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":73813,"jvmStartTime":1661085599920,"availableProcessors":12,"loadAverage":1.15,"totalInit":1060438016,"totalUsed":546311216,"totalCommitted":1396752384,"pid":529486,"jvmName":"529486@rs2","jvmVendor":"Ubuntu","jvmVersion":"11.0.16+8-post-Ubuntu-0ubuntu120.04","osDistribution":"Ubuntu
> 20.04.4
> LTS","agentCount":5,"heapMemoryUsed":374675976,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threadsDaemonCount":13,"threadsRunnableCount":14,"threadsTerminatedCount":0,"threadsTotalCount":204,"threadsWaitingCount":106,"systemMemoryTotal":67325091840,"systemMemoryFree":56703590400,"systemMemoryUsed":1156256,"systemMemoryVirtualSize":10498306048,"logInfo":"/var/log/cloudstack/management/management-server.log
> using: 716K\non disk /dev/md2 mounted on / (5%
> full)","systemTotalCpuCycles":18698.267999999996,"systemLoadAverages":[1.15,0.77,0.72],"systemCyclesUsage":[2830276,436788,51258857],"dbLocal":true,"usageLocal":true,"systemBootTime":"Aug
> 20, 2022, 11:58:58 PM","kernelVersion":"5.4.0-124-generic"} to
> 279278805472482
> 2022-08-21 12:41:13,816 DEBUG [c.c.c.ClusterManagerImpl]
> (Cluster-Worker-1:ctx-0800380a) (logid:33fbe11e) Cluster PDU
> 279278805472482 -> 279278805472482. agent: 0, pdu seq: 3, pdu ack seq: 0,
> json:
> {"managementServerHostId":3,"managementServerHostUuid":"7f5d510c-b780-4d98-91ec-ce43c8a673d2","collectionTime":"Aug
> 21, 2022, 12:41:13
> PM","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":1216872448,"freeJvmMemoryBytes":842738392,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":73813,"jvmStartTime":1661085599920,"availableProcessors":12,"loadAverage":1.15,"totalInit":1060438016,"totalUsed":546311216,"totalCommitted":1396752384,"pid":529486,"jvmName":"529486@rs2","jvmVendor":"Ubuntu","jvmVersion":"11.0.16+8-post-Ubuntu-0ubuntu120.04","osDistribution":"Ubuntu
> 20.04.4
> LTS","agentCount":5,"heapMemoryUsed":374675976,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threadsDaemonCount":13,"threadsRunnableCount":14,"threadsTerminatedCount":0,"threadsTotalCount":204,"threadsWaitingCount":106,"systemMemoryTotal":67325091840,"systemMemoryFree":56703590400,"systemMemoryUsed":1156256,"systemMemoryVirtualSize":10498306048,"logInfo":"/var/log/cloudstack/management/management-server.log
> using: 716K\non disk /dev/md2 mounted on / (5%
> full)","systemTotalCpuCycles":18698.267999999996,"systemLoadAverages":[1.15,0.77,0.72],"systemCyclesUsage":[2830276,436788,51258857],"dbLocal":true,"usageLocal":true,"systemBootTime":"Aug
> 20, 2022, 11:58:58 PM","kernelVersion":"5.4.0-124-generic"}
> 2022-08-21 12:41:13,822 DEBUG [c.c.s.StatsCollector]
> (Cluster-Worker-8:ctx-d68b7c8b) (logid:a5ba3e15) StatusUpdate from
> 279278805472482, json:
> {"managementServerHostId":3,"managementServerHostUuid":"7f5d510c-b780-4d98-91ec-ce43c8a673d2","collectionTime":"Aug
> 21, 2022, 12:41:13
> PM","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":1216872448,"freeJvmMemoryBytes":842738392,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":73813,"jvmStartTime":1661085599920,"availableProcessors":12,"loadAverage":1.15,"totalInit":1060438016,"totalUsed":546311216,"totalCommitted":1396752384,"pid":529486,"jvmName":"529486@rs2","jvmVendor":"Ubuntu","jvmVersion":"11.0.16+8-post-Ubuntu-0ubuntu120.04","osDistribution":"Ubuntu
> 20.04.4
> LTS","agentCount":5,"heapMemoryUsed":374675976,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threadsDaemonCount":13,"threadsRunnableCount":14,"threadsTerminatedCount":0,"threadsTotalCount":204,"threadsWaitingCount":106,"systemMemoryTotal":67325091840,"systemMemoryFree":56703590400,"systemMemoryUsed":1156256,"systemMemoryVirtualSize":10498306048,"logInfo":"/var/log/cloudstack/management/management-server.log
> using: 716K\non disk /dev/md2 mounted on / (5%
> full)","systemTotalCpuCycles":18698.267999999996,"systemLoadAverages":[1.15,0.77,0.72],"systemCyclesUsage":[2830276,436788,51258857],"dbLocal":true,"usageLocal":true,"systemBootTime":"Aug
> 20, 2022, 11:58:58 PM","kernelVersion":"5.4.0-124-generic"}
> 2022-08-21 12:41:13,822 DEBUG [c.c.c.ClusterServiceServletImpl]
> (Cluster-Worker-1:ctx-0800380a) (logid:33fbe11e) POST
> http://141.94.254.130:9090/clusterservice response :true, responding
> time: 4 ms
> 2022-08-21 12:41:13,822 DEBUG [c.c.c.ClusterManagerImpl]
> (Cluster-Worker-1:ctx-0800380a) (logid:33fbe11e) Cluster PDU
> 279278805472482 -> 279278805472482 completed. time: 5ms. agent: 0, pdu seq:
> 3, pdu ack seq: 0, json:
> {"managementServerHostId":3,"managementServerHostUuid":"7f5d510c-b780-4d98-91ec-ce43c8a673d2","collectionTime":"Aug
> 21, 2022, 12:41:13
> PM","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":1216872448,"freeJvmMemoryBytes":842738392,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":73813,"jvmStartTime":1661085599920,"availableProcessors":12,"loadAverage":1.15,"totalInit":1060438016,"totalUsed":546311216,"totalCommitted":1396752384,"pid":529486,"jvmName":"529486@rs2","jvmVendor":"Ubuntu","jvmVersion":"11.0.16+8-post-Ubuntu-0ubuntu120.04","osDistribution":"Ubuntu
> 20.04.4
> LTS","agentCount":5,"heapMemoryUsed":374675976,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threadsDaemonCount":13,"threadsRunnableCount":14,"threadsTerminatedCount":0,"threadsTotalCount":204,"threadsWaitingCount":106,"systemMemoryTotal":67325091840,"systemMemoryFree":56703590400,"systemMemoryUsed":1156256,"systemMemoryVirtualSize":10498306048,"logInfo":"/var/log/cloudstack/management/management-server.log
> using: 716K\non disk /dev/md2 mounted on / (5%
> full)","systemTotalCpuCycles":18698.267999999996,"systemLoadAverages":[1.15,0.77,0.72],"systemCyclesUsage":[2830276,436788,51258857],"dbLocal":true,"usageLocal":true,"systemBootTime":"Aug
> 20, 2022, 11:58:58 PM","kernelVersion":"5.4.0-124-generic"}
> 2022-08-21 12:41:13,827 DEBUG [o.a.c.h.HAManagerImpl]
> (BackgroundTaskPollManager-6:ctx-b914b8f5) (logid:a424d64d) HA health check
> task is running...
> 2022-08-21 12:41:15,438 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-8:null) (logid:) SeqA 3-1161: Processing Seq 3-1161:
> { Cmd , MgmtId: -1, via: 3, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"1012","_loadInfo":"{
> "connections": []
> }","wait":"0","bypassHostMaintenance":"false"}}] }
> 2022-08-21 12:41:15,442 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-8:null) (logid:) SeqA 3-1161: Sending Seq 3-1161: {
> Ans: , MgmtId: 279278805472482, via: 3, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
> }
> 2022-08-21 12:41:16,859 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-5:null) (logid:) Ping from Routing host 43(rs2)
> 2022-08-21 12:41:16,859 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-5:null) (logid:) Process host VM state report from
> ping process. host: 43
> 2022-08-21 12:41:16,860 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-5:null) (logid:) Unable to find matched VM in
> CloudStack DB. name: s-1011-VM
> 2022-08-21 12:41:16,862 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-5:null) (logid:) Unable to find matched VM in
> CloudStack DB. name: v-1012-VM
> 2022-08-21 12:41:16,864 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-5:null) (logid:) Process VM state report. host: 43,
> number of records in report: 2
> 2022-08-21 12:41:16,864 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-5:null) (logid:) VM state report. host: 43, vm id:
> 1013, power state: PowerOn
> 2022-08-21 12:41:16,887 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-5:null) (logid:) VM state report is updated. host:
> 43, vm id: 1013, power state: PowerOn
> 2022-08-21 12:41:16,905 DEBUG [c.c.c.CapacityManagerImpl]
> (AgentManager-Handler-5:null) (logid:) VM instance {id: "1013", name:
> "s-1013-VM", uuid: "fb415118-d8c8-4b39-824f-989392efdd7e",
> type="SecondaryStorageVm"} state transited from [Running] to [Running] with
> event [FollowAgentPowerOnReport]. VM's original host: Host {"id": "43",
> "name": "rs2", "uuid": "a3c2ef7e-d639-4dba-b727-e7bd0c371e4c",
> "type"="Routing"}, new host: Host {"id": "43", "name": "rs2", "uuid":
> "a3c2ef7e-d639-4dba-b727-e7bd0c371e4c", "type"="Routing"}, host before
> state transition: Host {"id": "43", "name": "rs2", "uuid":
> "a3c2ef7e-d639-4dba-b727-e7bd0c371e4c", "type"="Routing"}
> 2022-08-21 12:41:16,907 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-5:null) (logid:) VM state report. host: 43, vm id:
> 1014, power state: PowerOn
> 2022-08-21 12:41:16,924 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-5:null) (logid:) VM state report is updated. host:
> 43, vm id: 1014, power state: PowerOn
> 2022-08-21 12:41:16,942 DEBUG [c.c.c.CapacityManagerImpl]
> (AgentManager-Handler-5:null) (logid:) VM instance {id: "1014", name:
> "v-1014-VM", uuid: "1b61e89b-39d2-44b1-a080-bb12c6cd642a",
> type="ConsoleProxy"} state transited from [Running] to [Running] with event
> [FollowAgentPowerOnReport]. VM's original host: Host {"id": "43", "name":
> "rs2", "uuid": "a3c2ef7e-d639-4dba-b727-e7bd0c371e4c", "type"="Routing"},
> new host: Host {"id": "43", "name": "rs2", "uuid":
> "a3c2ef7e-d639-4dba-b727-e7bd0c371e4c", "type"="Routing"}, host before
> state transition: Host {"id": "43", "name": "rs2", "uuid":
> "a3c2ef7e-d639-4dba-b727-e7bd0c371e4c", "type"="Routing"}
> 2022-08-21 12:41:16,948 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-5:null) (logid:) Done with process of VM state
> report. host: 43
> 2022-08-21 12:41:17,699 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Vm-Operations-Cleanup-1:ctx-a9a4e267) (logid:fac80e14) VM Operation Thread
> Running
> 2022-08-21 12:41:17,828 DEBUG [o.a.c.h.HAManagerImpl]
> (BackgroundTaskPollManager-6:ctx-6ff6af51) (logid:882a492b) HA health check
> task is running...
> 2022-08-21 12:41:20,540 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-317:ctx-4d92813c) (logid:6d8fd4ea) ===START=== 91.17.169.4
> -- GET
>
> listall=true&page=1&pagesize=20&showIcon=true&command=listVirtualMachinesMetrics&response=json
> 2022-08-21 12:41:20,553 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-317:ctx-4d92813c ctx-f88de8a7) (logid:6d8fd4ea) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:41:20,618 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-317:ctx-4d92813c ctx-f88de8a7) (logid:6d8fd4ea) ===END===
> 91.17.169.4 -- GET
>
> listall=true&page=1&pagesize=20&showIcon=true&command=listVirtualMachinesMetrics&response=json
> 2022-08-21 12:41:21,091 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-6:null) (logid:) SeqA 44-981: Processing Seq 44-981:
> { Cmd , MgmtId: -1, via: 44, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"1014","_loadInfo":"{
> "connections": []
> }","wait":"0","bypassHostMaintenance":"false"}}] }
> 2022-08-21 12:41:21,108 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-6:null) (logid:) SeqA 44-981: Sending Seq 44-981: {
> Ans: , MgmtId: 279278805472482, via: 44, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
> }
> 2022-08-21 12:41:21,829 DEBUG [o.a.c.h.HAManagerImpl]
> (BackgroundTaskPollManager-6:ctx-0f0a7ec8) (logid:c069e960) HA health check
> task is running...
> 2022-08-21 12:41:22,688 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-22:ctx-78621989) (logid:6ef9640f) ===START=== 91.17.169.4
> -- GET command=&response=json
> 2022-08-21 12:41:22,694 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-22:ctx-78621989 ctx-619e01d7) (logid:6ef9640f) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:41:22,695 WARN [c.c.a.ApiServer]
> (qtp1778629809-22:ctx-78621989 ctx-619e01d7) (logid:6ef9640f) Unknown API
> command:
> 2022-08-21 12:41:22,695 INFO [c.c.a.ApiServer]
> (qtp1778629809-22:ctx-78621989 ctx-619e01d7) (logid:6ef9640f) Unknown API
> command:
> 2022-08-21 12:41:22,695 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-22:ctx-78621989 ctx-619e01d7) (logid:6ef9640f) ===END===
> 91.17.169.4 -- GET command=&response=json
> 2022-08-21 12:41:22,725 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-17:ctx-f267b180) (logid:b89346b6) ===START=== 91.17.169.4
> -- GET listall=true&showicon=true&command=listZones&response=json
> 2022-08-21 12:41:22,732 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-17:ctx-f267b180 ctx-ffa8ece3) (logid:b89346b6) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:41:22,735 WARN [c.c.a.d.ParamGenericValidationWorker]
> (qtp1778629809-17:ctx-f267b180 ctx-ffa8ece3) (logid:b89346b6) Received
> unknown parameters for command listZones. Unknown parameters : listall
> 2022-08-21 12:41:22,735 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-319:ctx-dd0e2402) (logid:5ddbde5e) ===START=== 91.17.169.4
> -- GET listall=true&command=listZones&response=json
> 2022-08-21 12:41:22,736 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-23:ctx-82fc9cd2) (logid:545b5936) ===START=== 91.17.169.4
> -- GET listall=true&command=listPods&response=json
> 2022-08-21 12:41:22,738 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-17:ctx-f267b180 ctx-ffa8ece3) (logid:b89346b6) ===END===
> 91.17.169.4 -- GET
> listall=true&showicon=true&command=listZones&response=json
> 2022-08-21 12:41:22,738 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-319:ctx-dd0e2402 ctx-aa6010b9) (logid:5ddbde5e) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:41:22,739 DEBUG [c.c.a.ApiServer]
> (qtp1778629809-23:ctx-82fc9cd2 ctx-7fb22c35) (logid:545b5936) CIDRs from
> which account 'Acct[03d17350-20e1-11ed-b119-d05099fd35ab-admin] -- Account
> {"id": 2, "name": "admin", "uuid": "03d17350-20e1-11ed-b119-d05099fd35ab"}'
> is allowed to perform API calls: 0.0.0.0/0,::/0
> 2022-08-21 12:41:22,739 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-316:ctx-c9f8b1e3) (logid:8ff68ed9) ===START=== 91.17.169.4
> -- GET listall=true&command=listClusters&response=json
> 2022-08-21 12:41:22,739 DEBUG [c.c.a.ApiServlet]
> (qtp1778629809-318:ctx-54adef22) (logid:9eab7c37) ===START=== 91.17.169.4
> -- GET state=Up&type=Routing&listall=true&command=listHosts&response=json
> 2022-08-21 12:41:22,740 WARN [c.c.a.d.ParamGenericValidationWorker]
> (qtp1778629809-319:ctx-dd0e2402 ctx-aa6010b9) (logid:5ddbde5e) Received
> unknown parameters for command listZones. Unknown parameters : listall
> 2022-08-21 12:41:22,74
On Sun, Aug 21, 2022 at 2:21 PM Slavka Peleva <slav...@storpool.com.invalid>
wrote:
> Hi,
>
> Can you share everything from the management log with `logid:0e77f2bc`
> because it's not the whole log for this call (StartVMCmdByAdmin)?
>
> According to your shared log, no volumes are allocated to the pool. Also,
> is this VM already worked and then destroyed (without expunging)? What is
> the current state of the VM? Probably the deployment failed, and you tried
> to start the VM.
> If possible, can you try to deploy a new VM and share the log?
>
> Chris, the problem mentioned in the advisory shouldn't affect local
> storage.
>
> Best regards,
> Slavka
>
> On Sun, Aug 21, 2022 at 2:51 PM vas...@gmx.de <vas...@gmx.de> wrote:
>
> > HI,
> >
> > as a quick thought - have you seen the following advisorty
> >
> >
> https://blogs.apache.org/cloudstack/entry/advisory-apache-cloudstack-advisory-on
> >
> > also it would be helpful to see the agent logs from the host where the VM
> > shall be deployed to.
> > Regards,
> > Chris
> >
> > Am So., 21. Aug. 2022 um 13:09 Uhr schrieb Aufgabe Zwei <
> > aufgabez...@gmail.com>:
> >
> > > Hello,
> > >
> > > I would be grateful if you can assist or point me in the right
> direction.
> > >
> > > I have tried for almost a month to create a test deployment of
> cloudstack
> > > but each time I get to creating a vm instance, I get the error message
> > >
> > > Start instance
> > > > (VM1) Unable to create deployment, no usable volumes found for the
> VM:
> > > 1015
> > > >
> > >
> > > I tried to find a fix on my own and have literally done a lot of
> > searching
> > > and reading around but I just can find the reason.
> > >
> > > I have ensured that the host, storage are correctly tagged. I have
> > enabled
> > > local storage and created local service offerings
> > >
> > > I followed these guides:
> > >
> > > Quick Installation Guide — Apache CloudStack 4.17.0.0 documentation
> > > <
> > >
> >
> http://docs.cloudstack.apache.org/en/latest/quickinstallationguide/qig.html#setting-up-a-zone
> > > >
> > >
> > > hackerbook/1-user.md at main · shapeblue/hackerbook · GitHub
> > > <
> https://github.com/shapeblue/hackerbook/blob/main/1-user.md#nfs-server>
> > >
> > > Thank you
> > >
> > > management log:
> > >
> > > > 2022-08-21 10:58:58,379 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb)
> > (logid:0e77f2bc)
> > > > Trying to allocate a host and storage pools from dc:1,
> > > > pod:null,cluster:null, requested cpu: 4500, requested ram: (2.00 GB)
> > > > 2147483648
> > > > 2022-08-21 10:58:58,379 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb)
> > (logid:0e77f2bc)
> > > Is
> > > > ROOT volume READY (pool already allocated)?: No
> > > > 2022-08-21 10:58:58,381 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb)
> > (logid:0e77f2bc)
> > > > Deploy avoids pods: [], clusters: [], hosts: []
> > > > 2022-08-21 10:58:58,381 DEBUG [c.c.d.FirstFitPlanner]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb)
> > (logid:0e77f2bc)
> > > > Searching all possible resources under this Zone: 1
> > > > 2022-08-21 10:58:58,382 DEBUG [c.c.d.FirstFitPlanner]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb)
> > (logid:0e77f2bc)
> > > > Listing clusters in order of aggregate capacity, that have (at least
> > one
> > > > host with) enough CPU and RAM capacity under this Zone: 1
> > > > 2022-08-21 10:58:58,383 DEBUG [c.c.d.FirstFitPlanner]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb)
> > (logid:0e77f2bc)
> > > > Removing from the clusterId list these clusters from avoid set: []
> > > > 2022-08-21 10:58:58,384 DEBUG [c.c.d.FirstFitPlanner]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb)
> > (logid:0e77f2bc)
> > > > The clusterId list for the given offering tag: [1]
> > > > 2022-08-21 10:58:58,385 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb)
> > (logid:0e77f2bc)
> > > > Checking resources in Cluster: 1 under Pod: 1
> > > > 2022-08-21 10:58:58,386 INFO [c.c.a.m.a.i.FirstFitAllocator]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > > FirstFitRoutingAllocator) (logid:0e77f2bc) Guest VM is requested
> with
> > > > Custom[UEFI] Boot Type false
> > > > 2022-08-21 10:58:58,386 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > > FirstFitRoutingAllocator) (logid:0e77f2bc) Looking for hosts in dc: 1
> > > > pod:1 cluster:1
> > > > 2022-08-21 10:58:58,386 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > > FirstFitRoutingAllocator) (logid:0e77f2bc) Looking for hosts having
> tag
> > > > specified on SvcOffering:local
> > > > 2022-08-21 10:58:58,386 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > > FirstFitRoutingAllocator) (logid:0e77f2bc) Hosts with tag 'local'
> > > are:[Host
> > > > {"id": "43", "name": "rs2", "uuid":
> > > "a3c2ef7e-d639-4dba-b727-e7bd0c371e4c",
> > > > "type"="Routing"}]
> > > > 2022-08-21 10:58:58,386 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > > FirstFitRoutingAllocator) (logid:0e77f2bc) FirstFitAllocator has 1
> > hosts
> > > to
> > > > check for allocation: [Host {"id": "43", "name": "rs2", "uuid":
> > > > "a3c2ef7e-d639-4dba-b727-e7bd0c371e4c", "type"="Routing"}]
> > > > 2022-08-21 10:58:58,387 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > > FirstFitRoutingAllocator) (logid:0e77f2bc) Found 1 hosts for
> allocation
> > > > after prioritization: [Host {"id": "43", "name": "rs2", "uuid":
> > > > "a3c2ef7e-d639-4dba-b727-e7bd0c371e4c", "type"="Routing"}]
> > > > 2022-08-21 10:58:58,387 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > > FirstFitRoutingAllocator) (logid:0e77f2bc) Looking for speed=4500Mhz,
> > > > Ram=2048 MB
> > >
> > > 2022-08-21 10:58:58,387 DEBUG [c.c.c.CapacityManagerImpl]
> > > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > > FirstFitRoutingAllocator) (logid:0e77f2bc) Host {id: 43, name: rs2,
> > uuid:
> > > > a3c2ef7e-d639-4dba-b727-e7bd0c371e4c} is KVM hypervisor type, no max
> > > guest
> > > > limit check needed
> > >
> > > 2022-08-21 10:58:58,388 DEBUG [c.c.c.CapacityManagerImpl]
> > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > FirstFitRoutingAllocator) (logid:0e77f2bc) Host: 43 has cpu capability
> > > (cpu:12, speed:3500) to support requested CPU: 3 and requested speed:
> > 1500
> > > 2022-08-21 10:58:58,388 DEBUG [c.c.c.CapacityManagerImpl]
> > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > FirstFitRoutingAllocator) (logid:0e77f2bc) Checking if host: 43 has
> > enough
> > > capacity for requested CPU: 4500 and requested RAM: (2.00 GB)
> 2147483648
> > ,
> > > cpuOverprovisioningFactor: 1.0
> > > 2022-08-21 10:58:58,389 DEBUG [c.c.c.CapacityManagerImpl]
> > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > FirstFitRoutingAllocator) (logid:0e77f2bc) Hosts's actual total CPU:
> > 42000
> > > and CPU after applying overprovisioning: 42000
> > > 2022-08-21 10:58:58,389 DEBUG [c.c.c.CapacityManagerImpl]
> > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > FirstFitRoutingAllocator) (logid:0e77f2bc) Free CPU: 41000 , Requested
> > CPU:
> > > 4500
> > > 2022-08-21 10:58:58,389 DEBUG [c.c.c.CapacityManagerImpl]
> > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > FirstFitRoutingAllocator) (logid:0e77f2bc) Free RAM: (60.20 GB)
> > 64640737280
> > > , Requested RAM: (2.00 GB) 2147483648
> > > 2022-08-21 10:58:58,389 DEBUG [c.c.c.CapacityManagerImpl]
> > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > FirstFitRoutingAllocator) (logid:0e77f2bc) Host has enough CPU and RAM
> > > available
> > > 2022-08-21 10:58:58,389 DEBUG [c.c.c.CapacityManagerImpl]
> > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > FirstFitRoutingAllocator) (logid:0e77f2bc) STATS: Can alloc CPU from
> > host:
> > > 43, used: 1000, reserved: 0, actual total: 42000, total with
> > > overprovisioning: 42000; requested cpu:4500,alloc_from_last_host?:false
> > > ,considerReservedCapacity?: true
> > > 2022-08-21 10:58:58,389 DEBUG [c.c.c.CapacityManagerImpl]
> > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > FirstFitRoutingAllocator) (logid:0e77f2bc) STATS: Can alloc MEM from
> > host:
> > > 43, used: (1.50 GB) 1610612736, reserved: (0 bytes) 0, total: (61.70
> GB)
> > > 66251350016; requested mem: (2.00 GB) 2147483648,
> alloc_from_last_host?:
> > > false , considerReservedCapacity?: true
> > > 2022-08-21 10:58:58,389 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > FirstFitRoutingAllocator) (logid:0e77f2bc) Found a suitable host,
> adding
> > to
> > > list: 43
> > > 2022-08-21 10:58:58,389 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> > > (API-Job-Executor-8:ctx-a898686b job-3069 ctx-2b5b16cb
> > > FirstFitRoutingAllocator) (logid:0e77f2bc) Host Allocator returning 1
> > > suitable hosts
> > > 2022-08-21 10:58:58,402 ERROR [c.c.a.ApiAsyncJobDispatcher]
> > > (API-Job-Executor-8:ctx-a898686b job-3069) (logid:0e77f2bc) Unexpected
> > > exception while executing
> > > org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin
> > > com.cloud.utils.exception.CloudRuntimeException: Unable to create
> > > deployment, no usable volumes found for the VM: 1015
> > > at
> > >
> > >
> >
> com.cloud.deploy.DeploymentPlanningManagerImpl.findSuitablePoolsForVolumes(DeploymentPlanningManagerImpl.java:1569)
> > > at
> > >
> > >
> >
> com.cloud.deploy.DeploymentPlanningManagerImpl.checkClustersforDestination(DeploymentPlanningManagerImpl.java:1217)
> > > at
> > >
> > >
> >
> com.cloud.deploy.DeploymentPlanningManagerImpl.planDeployment(DeploymentPlanningManagerImpl.java:527)
> > > at
> > >
> > >
> >
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:203)
> > > at
> > >
> > >
> >
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:202)
> > > at
> > >
> > >
> >
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:5280)
> > > at
> > >
> > >
> >
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:5131)
> > > at
> > >
> > >
> >
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3115)
> > > at
> > > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
> > > Method)
> > > at
> > >
> > >
> >
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> > > at
> > >
> > >
> >
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> > > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> > > at
> > >
> > >
> >
> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
> > > at
> > >
> > >
> >
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
> > > 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:175)
> > > at
> > >
> > >
> >
> com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:52)
> > > >
> > > > at
> > > >
> > >
> >
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
> > >
> > > at
> > >
> > >
> >
> org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
> > > at
> > >
> > >
> >
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
> > > at
> > >
> > >
> >
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
> > > at com.sun.proxy.$Proxy128.startVirtualMachine(Unknown Source)
> > > at
> > >
> > >
> >
> org.apache.cloudstack.api.command.user.vm.StartVMCmd.execute(StartVMCmd.java:169)
> > > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:163)
> > > at
> > >
> >
> com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:106)
> > > at
> > >
> > >
> >
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620)
> > > at
> > >
> > >
> >
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
> > > at
> > >
> > >
> >
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
> > > at
> > >
> > >
> >
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
> > > at
> > >
> > >
> >
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
> > > at
> > >
> > >
> >
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
> > > at
> > >
> > >
> >
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
> > > at
> > >
> > >
> >
> java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
> > > at
> > > java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> > > at
> > >
> > >
> >
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> > > at
> > >
> > >
> >
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> > > at java.base/java.lang.Thread.run(Thread.java:829)
> > > 2022-08-21 10:58:58,402 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> > > (API-Job-Executor-8:ctx-a898686b job-3069) (logid:0e77f2bc) Complete
> > async
> > > job-3069, jobStatus: FAILED, resultCode: 530, result:
> > >
> > >
> >
> org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":"530","errortext":"Unable
> > > to create deployment, no usable volumes found for the VM: 1015"}
> > > 2022-08-21 10:58:58,402 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> > > (API-Job-Executor-8:ctx-a898686b job-3069) (logid:0e77f2bc) Publish
> async
> > > job-3069 complete on message bus
> > > >
> > > >
> > >
> >
>
