Thanks for the logs!
Do you have another primary storage, or do you use only the local one?
- Can you check if local storage is enabled for the Zone?
- Check the tags of the primary storage. Also, the scope has to be
`HOST` and the type `FileSystem`.
- Check the storage tags of the compute offering (they should be the
same as the primary storage tags) and the Storage type - it should be
`local`. Sometimes I forget to mark it as a local when creating a new
Service offering, and I face the same problem when I try to deploy a VM.
Best regards,
Slavka
On Sun, Aug 21, 2022 at 4:14 PM Aufgabe Zwei <aufgabez...@gmail.com> wrote:
> 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
> > > > >
> > > > >
> > > >
> > >
> >
>
