[GitHub] [cloudstack] whitetiger264 commented on issue #6836: Volume Snapshots Failing After 3600 Seconds

[GitBox]

whitetiger264 commented on issue #6836:
URL: https://github.com/apache/cloudstack/issues/6836#issuecomment-1282842228

   Here's the `agent.log` for the successful volume snapshot for this one VM:
   
   ```
   2022-10-18 20:12:04,515 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-4:null) (logid:e6b6cd8e) Processing command: 
com.cloud.agent.api.GetVmStatsCommand
   2022-10-18 20:12:04,515 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:e6b6cd8e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:04,536 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:e6b6cd8e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:04,546 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-5:null) (logid:2b718228) Processing command: 
com.cloud.agent.api.GetHostStatsCommand
   2022-10-18 20:12:04,556 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:e6b6cd8e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:04,577 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:e6b6cd8e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:04,597 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:e6b6cd8e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:04,617 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:e6b6cd8e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:04,626 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:e6b6cd8e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:04,634 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:e6b6cd8e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:04,656 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:e6b6cd8e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:04,665 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:e6b6cd8e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:21,094 DEBUG [kvm.resource.LibvirtConnection] 
(Thread-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:12:21,107 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Found NFS storage pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89] in 
libvirt, continuing.
   2022-10-18 20:12:21,107 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP 
   2022-10-18 20:12:21,114 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing while with timeout : 60000
   2022-10-18 20:12:21,135 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Execution is successful.
   2022-10-18 20:12:21,135 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) The command 
(/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP ), to the pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89], has the 
result [null].
   2022-10-18 20:12:42,073 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/network/security_group.py 
get_rule_logs_for_vms 
   2022-10-18 20:12:42,074 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing while with timeout : 1800000
   2022-10-18 20:12:42,194 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Execution is successful.
   2022-10-18 20:12:42,194 DEBUG [kvm.resource.LibvirtConnection] 
(UgentTask-5:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:12:42,213 DEBUG [cloud.agent.Agent] (UgentTask-5:null) 
(logid:) Sending ping: Seq 1-1589:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 
11, 
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{"i-2-38-VM":["38","3"],"i-2-37-VM":["37","3"],"i-2-27-VM":["27","9"],"i-2-23-VM":["23","12"],"i-2-19-VM":["19","11"],"i-2-31-VM":["31","6"],"i-2-35-VM":["35","5"],"i-2-29-VM":["29","6"],"i-2-36-VM":["36","3"],"i-2-28-VM":["28","8"]},"_hostVmStateReport":{"s-43-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-27-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-23-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-19-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-31-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-35-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-36-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-38-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-37-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"r-32-VM":{"state":"PowerOn","host":"K
 
VMHOSTNAME"},"i-2-29-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-28-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"v-11-VM":{"state":"PowerOn","host":"KVMHOSTNAME"}},"_gatewayAccessible":"true","_vnetAccessible":"true","hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:12:42,285 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) 
(logid:b59cc776) Received response: Seq 1-1589:  { Ans: , MgmtId: 2619780474, 
via: 1, Ver: v1, Flags: 100010, 
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"},"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:12:54,473 DEBUG [kvm.storage.KVMStorageProcessor] 
(agentRequest-Handler-3:null) (logid:5af967f1) Copied 
volumeTO[uuid=b21551c6-8276-4e58-841e-4e5a02c0e163|path=b21551c6-8276-4e58-841e-4e5a02c0e163|datastore=PrimaryDataStoreTO[uuid=81ffca3a-9775-375d-a1c0-9504c0ec3d89|name=Primary|id=2|pooltype=NetworkFilesystem]]
 snapshot from 
[/mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89/b21551c6-8276-4e58-841e-4e5a02c0e163]
 to 
[/mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89/snapshots/d17e1814-84c1-4526-946e-76486d8dc654].
   2022-10-18 20:12:54,473 DEBUG [resource.wrapper.LibvirtUtilitiesHelper] 
(agentRequest-Handler-3:null) (logid:5af967f1) The current Libvirt's version 
[8000000] supports the flag '--delete' on command 'virsh blockcommit'.
   2022-10-18 20:12:54,473 DEBUG [utils.script.Script] 
(agentRequest-Handler-3:null) (logid:5af967f1) Executing: /bin/bash -c virsh 
blockcommit i-2-28-VM hda --base 
/mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89/b21551c6-8276-4e58-841e-4e5a02c0e163 
--active --wait --delete --pivot 
   2022-10-18 20:12:54,474 DEBUG [utils.script.Script] 
(agentRequest-Handler-3:null) (logid:5af967f1) Executing while with timeout : 
3600000
   2022-10-18 20:12:56,843 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:8da874d3) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:12:56,843 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:8da874d3) Trying to fetch storage pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 from libvirt
   2022-10-18 20:12:56,843 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:8da874d3) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:56,856 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:8da874d3) Asking libvirt to refresh 
storage pool ff9a58d8-fb77-49c8-92d1-7c82fc456297
   2022-10-18 20:12:56,858 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:8da874d3) Successfully refreshed pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 Capacity: (1,6853 TB) 1853047648256 Used: 
(5,96 GB) 6402666496 Available: (1,6795 TB) 1846644981760
   2022-10-18 20:12:56,946 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:8da874d3) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:12:56,946 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:8da874d3) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:12:56,946 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:8da874d3) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:56,959 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:8da874d3) Asking libvirt to refresh 
storage pool 81ffca3a-9775-375d-a1c0-9504c0ec3d89
   2022-10-18 20:12:57,087 DEBUG [utils.script.Script] 
(agentRequest-Handler-3:null) (logid:5af967f1) Execution is successful.
   2022-10-18 20:12:57,087 DEBUG [kvm.storage.KVMStorageProcessor] 
(agentRequest-Handler-3:null) (logid:5af967f1) Successfully merged snapshot 
[d17e1814-84c1-4526-946e-76486d8dc654] into VM [i-2-28-VM] 
volumeTO[uuid=b21551c6-8276-4e58-841e-4e5a02c0e163|path=b21551c6-8276-4e58-841e-4e5a02c0e163|datastore=PrimaryDataStoreTO[uuid=81ffca3a-9775-375d-a1c0-9504c0ec3d89|name=Primary|id=2|pooltype=NetworkFilesystem]]
 base file.
   2022-10-18 20:12:57,087 DEBUG [kvm.storage.KVMStorageProcessor] 
(agentRequest-Handler-3:null) (logid:5af967f1) The current Libvirt's version 
supports the flag '--delete' on command 'virsh blockcommit', we will skip the 
manually deletion of the unused snapshot file 
[/mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89/d17e1814-84c1-4526-946e-76486d8dc654]
 as it already was automatically deleted.
   2022-10-18 20:12:57,088 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-3:null) (logid:5af967f1) Seq 1-1590615093391918180:  { 
Ans: , MgmtId: 2619780474, via: 1, Ver: v1, Flags: 10, 
[{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89/snapshots/d17e1814-84c1-4526-946e-76486d8dc654","id":"0","quiescevm":"false","physicalSize":"0"}},"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
 }
     2022-10-18 20:12:57,227 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-5:null) (logid:5af967f1) Request:Seq 
1-1590615093391918295:  { Cmd , MgmtId: 2619780474, via: 1, Ver: v1, Flags: 
100011, 
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89/snapshots/d17e1814-84c1-4526-946e-76486d8dc654","volume":{"uuid":"b21551c6-8276-4e58-841e-4e5a02c0e163","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"81ffca3a-9775-375d-a1c0-9504c0ec3d89","name":"Primary","id":"2","poolType":"NetworkFilesystem","host":"MANAGEMENTHOSTIP","path":"/mnt/primary","port":"2049","url":"NetworkFilesystem://MANAGEMENTHOSTIP/mnt/primary/?ROLE=Primary&STOREUUID=81ffca3a-9775-375d-a1c0-9504c0ec3d89","isManaged":"false"}},"name":"ROOT-28","size":"(60,00
 GB) 
64424509440","path":"b21551c6-8276-4e58-841e-4e5a02c0e163","volumeId":"35","vmName":"i-2-28-VM","acc
 
ountId":"2","format":"QCOW2","provisioningType":"THIN","poolId":"2","id":"35","deviceId":"0","cacheMode":"NONE","hypervisorType":"KVM","directDownload":"false","deployAsIs":"false"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"81ffca3a-9775-375d-a1c0-9504c0ec3d89","name":"Primary","id":"2","poolType":"NetworkFilesystem","host":"MANAGEMENTHOSTIP","path":"/mnt/primary","port":"2049","url":"NetworkFilesystem://MANAGEMENTHOSTIP/mnt/primary/?ROLE=Primary&STOREUUID=81ffca3a-9775-375d-a1c0-9504c0ec3d89","isManaged":"false"}},"vmName":"i-2-28-VM","name":"Confidente_test001","hypervisorType":"KVM","id":"36","quiescevm":"false","physicalSize":"0"}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/35","volume":{"uuid":"b21551c6-8276-4e58-841e-4e5a02c0e163","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"81ffca3a-9775-375d-a1c0-9504c0ec3d89","name":"Primary","id":"2","poolType":"Netw
 
orkFilesystem","host":"MANAGEMENTHOSTIP","path":"/mnt/primary","port":"2049","url":"NetworkFilesystem://MANAGEMENTHOSTIP/mnt/primary/?ROLE=Primary&STOREUUID=81ffca3a-9775-375d-a1c0-9504c0ec3d89","isManaged":"false"}},"name":"ROOT-28","size":"(60,00
 GB) 
64424509440","path":"b21551c6-8276-4e58-841e-4e5a02c0e163","volumeId":"35","vmName":"i-2-28-VM","accountId":"2","format":"QCOW2","provisioningType":"THIN","poolId":"2","id":"35","deviceId":"0","cacheMode":"NONE","hypervisorType":"KVM","directDownload":"false","deployAsIs":"false"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://MANAGEMENTHOSTIP/mnt/secondary","_role":"Image"}},"vmName":"i-2-28-VM","name":"Confidente_test001","hypervisorType":"KVM","id":"36","quiescevm":"false","physicalSize":"0"}},"executeInSequence":"false","options":{"snapshot.backup.to.secondary":"true","fullSnapshot":"true"},"options2":{},"wait":"21600","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:12:57,227 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-5:null) (logid:5af967f1) Processing command: 
org.apache.cloudstack.storage.command.CopyCommand
   2022-10-18 20:12:57,227 DEBUG 
[storage.resource.StorageSubsystemCommandHandlerBase] 
(agentRequest-Handler-5:null) (logid:5af967f1) Executing command CopyCommand: 
[{"srcTO":{"path":"/mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89/snapshots/d17e1814-84c1-4526-946e-76486d8dc654","volume":{"uuid":"b21551c6-8276-4e58-841e-4e5a02c0e163","volumeType":"ROOT","dataStore":{"uuid":"81ffca3a-9775-375d-a1c0-9504c0ec3d89","name":"Primary","id":2,"poolType":"NetworkFilesystem","host":"MANAGEMENTHOSTIP","path":"/mnt/primary","port":2049,"url":"NetworkFilesystem://MANAGEMENTHOSTIP/mnt/primary/?ROLE\u003dPrimary\u0026STOREUUID\u003d81ffca3a-9775-375d-a1c0-9504c0ec3d89","isManaged":false},"name":"ROOT-28","size":64424509440,"path":"b21551c6-8276-4e58-841e-4e5a02c0e163","volumeId":35,"vmName":"i-2-28-VM","accountId":2,"format":"QCOW2","provisioningType":"THIN","poolId":2,"id":35,"deviceId":0,"cacheMode":"NONE","hypervisorType":"KVM","directDownload":false,"deployAsIs":false},"dataStore":{"uuid":"81ffca3a-9
 
775-375d-a1c0-9504c0ec3d89","name":"Primary","id":2,"poolType":"NetworkFilesystem","host":"MANAGEMENTHOSTIP","path":"/mnt/primary","port":2049,"url":"NetworkFilesystem://MANAGEMENTHOSTIP/mnt/primary/?ROLE\u003dPrimary\u0026STOREUUID\u003d81ffca3a-9775-375d-a1c0-9504c0ec3d89","isManaged":false},"vmName":"i-2-28-VM","name":"Confidente_test001","hypervisorType":"KVM","id":36,"quiescevm":false,"physicalSize":0},"destTO":{"path":"snapshots/2/35","volume":{"uuid":"b21551c6-8276-4e58-841e-4e5a02c0e163","volumeType":"ROOT","dataStore":{"uuid":"81ffca3a-9775-375d-a1c0-9504c0ec3d89","name":"Primary","id":2,"poolType":"NetworkFilesystem","host":"MANAGEMENTHOSTIP","path":"/mnt/primary","port":2049,"url":"NetworkFilesystem://MANAGEMENTHOSTIP/mnt/primary/?ROLE\u003dPrimary\u0026STOREUUID\u003d81ffca3a-9775-375d-a1c0-9504c0ec3d89","isManaged":false},"name":"ROOT-28","size":64424509440,"path":"b21551c6-8276-4e58-841e-4e5a02c0e163","volumeId":35,"vmName":"i-2-28-VM","accountId":2,"format":"QCOW2","p
 
rovisioningType":"THIN","poolId":2,"id":35,"deviceId":0,"cacheMode":"NONE","hypervisorType":"KVM","directDownload":false,"deployAsIs":false},"dataStore":{"_url":"nfs://MANAGEMENTHOSTIP/mnt/secondary","_role":"Image"},"vmName":"i-2-28-VM","name":"Confidente_test001","hypervisorType":"KVM","id":36,"quiescevm":false,"physicalSize":0},"executeInSequence":false,"options":{"snapshot.backup.to.secondary":"true","fullSnapshot":"true"},"options2":{},"contextMap":{"logid":"5af967f1","job":"job-1000/job-1001"},"wait":21600,"bypassHostMaintenance":false}].
   2022-10-18 20:12:57,227 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-5:null) (logid:5af967f1) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:57,240 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Attempting to create storage 
pool 6ff3840c-b5c3-3355-8a93-5b9d5c44901b (NetworkFilesystem) in libvirt
   2022-10-18 20:12:57,240 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-5:null) (logid:5af967f1) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:57,253 WARN  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Storage pool 
6ff3840c-b5c3-3355-8a93-5b9d5c44901b was not found running in libvirt. Need to 
create it.
   2022-10-18 20:12:57,253 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Didn't find an existing storage 
pool 6ff3840c-b5c3-3355-8a93-5b9d5c44901b by UUID, checking for pools with 
duplicate paths
   2022-10-18 20:12:57,735 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Checking path of existing pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 against pool we want to create
   2022-10-18 20:12:57,736 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:8da874d3) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(355,81 GB) 382049714176 Available: (515,05 GB) 553031565312
   2022-10-18 20:12:57,736 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Checking path of existing pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 against pool we want to create
   2022-10-18 20:12:57,737 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Attempting to create storage 
pool 6ff3840c-b5c3-3355-8a93-5b9d5c44901b
   2022-10-18 20:12:57,737 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) <pool type='netfs'>
   <name>6ff3840c-b5c3-3355-8a93-5b9d5c44901b</name>
   <uuid>6ff3840c-b5c3-3355-8a93-5b9d5c44901b</uuid>
   <source>
   <host name='MANAGEMENTHOSTIP'/>
   <dir path='/mnt/secondary'/>
   </source>
   <target>
   <path>/mnt/6ff3840c-b5c3-3355-8a93-5b9d5c44901b</path>
   </target>
   </pool>
   
   2022-10-18 20:12:57,737 DEBUG [utils.script.Script] 
(agentRequest-Handler-5:null) (logid:5af967f1) Executing: /bin/bash -c 
mountpoint -q /mnt/6ff3840c-b5c3-3355-8a93-5b9d5c44901b 
   2022-10-18 20:12:57,738 DEBUG [utils.script.Script] 
(agentRequest-Handler-5:null) (logid:5af967f1) Executing while with timeout : 
3600000
   2022-10-18 20:12:57,741 DEBUG [utils.script.Script] 
(agentRequest-Handler-5:null) (logid:5af967f1) Exit value is 1
   2022-10-18 20:12:57,742 DEBUG [utils.script.Script] 
(agentRequest-Handler-5:null) (logid:5af967f1) 1
   2022-10-18 20:12:57,812 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Trying to fetch storage pool 
6ff3840c-b5c3-3355-8a93-5b9d5c44901b from libvirt
   2022-10-18 20:12:57,812 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-5:null) (logid:5af967f1) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:57,815 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Successfully refreshed pool 
6ff3840c-b5c3-3355-8a93-5b9d5c44901b Capacity: (870,86 GB) 935081279488 Used: 
(355,81 GB) 382049714176 Available: (515,05 GB) 553031565312
   2022-10-18 20:12:57,815 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:12:57,815 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-5:null) (logid:5af967f1) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:12:57,830 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(355,81 GB) 382049714176 Available: (515,05 GB) 553031565312
   2022-10-18 20:12:57,857 DEBUG [kvm.storage.KVMStorageProcessor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Executing: 
/usr/share/cloudstack-common/scripts/storage/qcow2/managesnapshot.sh -b 
/mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89/snapshots/d17e1814-84c1-4526-946e-76486d8dc654
 -n d17e1814-84c1-4526-946e-76486d8dc654 -p 
/mnt/6ff3840c-b5c3-3355-8a93-5b9d5c44901b/snapshots/2/35 -t 
d17e1814-84c1-4526-946e-76486d8dc654 
   2022-10-18 20:12:57,858 DEBUG [kvm.storage.KVMStorageProcessor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Executing while with timeout : 
21600000
   2022-10-18 20:13:04,555 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-4:null) (logid:ad2edd40) Processing command: 
com.cloud.agent.api.GetHostStatsCommand
   2022-10-18 20:13:04,756 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:37ed398c) Processing command: 
com.cloud.agent.api.GetVmStatsCommand
   2022-10-18 20:13:04,756 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:37ed398c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:04,779 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:37ed398c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:04,801 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:37ed398c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:04,823 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:37ed398c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:04,845 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:37ed398c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:04,866 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:37ed398c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:04,887 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:37ed398c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:04,896 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:37ed398c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:04,917 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:37ed398c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:04,926 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:37ed398c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:21,135 DEBUG [kvm.resource.LibvirtConnection] 
(Thread-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:13:21,148 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Found NFS storage pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89] in 
libvirt, continuing.
   2022-10-18 20:13:21,148 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP 
   2022-10-18 20:13:21,149 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing while with timeout : 60000
   2022-10-18 20:13:21,387 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Execution is successful.
   2022-10-18 20:13:21,387 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) The command 
(/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP ), to the pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89], has the 
result [null].
   2022-10-18 20:13:42,073 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/network/security_group.py 
get_rule_logs_for_vms 
   2022-10-18 20:13:42,074 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing while with timeout : 1800000
   2022-10-18 20:13:42,207 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Execution is successful.
   2022-10-18 20:13:42,207 DEBUG [kvm.resource.LibvirtConnection] 
(UgentTask-5:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:13:42,226 DEBUG [cloud.agent.Agent] (UgentTask-5:null) 
(logid:) Sending ping: Seq 1-1590:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 
11, 
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{"i-2-38-VM":["38","3"],"i-2-37-VM":["37","3"],"i-2-27-VM":["27","9"],"i-2-23-VM":["23","12"],"i-2-19-VM":["19","11"],"i-2-31-VM":["31","6"],"i-2-35-VM":["35","5"],"i-2-29-VM":["29","6"],"i-2-36-VM":["36","3"],"i-2-28-VM":["28","8"]},"_hostVmStateReport":{"s-43-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-27-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-23-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-19-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-31-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-35-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-36-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-38-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-37-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"r-32-VM":{"state":"PowerOn","host":"K
 
VMHOSTNAME"},"i-2-29-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-28-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"v-11-VM":{"state":"PowerOn","host":"KVMHOSTNAME"}},"_gatewayAccessible":"true","_vnetAccessible":"true","hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:13:42,277 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) 
(logid:a8c0b95d) Received response: Seq 1-1590:  { Ans: , MgmtId: 2619780474, 
via: 1, Ver: v1, Flags: 100010, 
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"},"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:13:57,820 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-3:null) (logid:9012cb2c) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:13:57,820 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:9012cb2c) Trying to fetch storage pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 from libvirt
   2022-10-18 20:13:57,820 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:9012cb2c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:57,835 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:9012cb2c) Asking libvirt to refresh 
storage pool ff9a58d8-fb77-49c8-92d1-7c82fc456297
   2022-10-18 20:13:57,837 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:9012cb2c) Successfully refreshed pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 Capacity: (1,6853 TB) 1853047648256 Used: 
(5,96 GB) 6402703360 Available: (1,6795 TB) 1846644944896
   2022-10-18 20:13:57,932 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:9012cb2c) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:13:57,932 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:9012cb2c) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:13:57,932 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:9012cb2c) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:13:57,946 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:9012cb2c) Asking libvirt to refresh 
storage pool 81ffca3a-9775-375d-a1c0-9504c0ec3d89
   2022-10-18 20:14:04,574 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-4:null) (logid:28aca9fd) Processing command: 
com.cloud.agent.api.GetHostStatsCommand
   2022-10-18 20:14:05,028 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:af4d41c4) Processing command: 
com.cloud.agent.api.GetVmStatsCommand
   2022-10-18 20:14:05,028 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:af4d41c4) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:14:05,048 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:af4d41c4) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:14:05,070 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:af4d41c4) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:14:05,091 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:af4d41c4) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:14:05,101 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:af4d41c4) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:14:05,122 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:af4d41c4) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:14:05,144 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:af4d41c4) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:14:05,153 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:af4d41c4) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:14:05,163 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:af4d41c4) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:14:05,172 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:af4d41c4) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:14:10,249 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:9012cb2c) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(356,51 GB) 382798397440 Available: (514,35 GB) 552282882048
   2022-10-18 20:14:21,387 DEBUG [kvm.resource.LibvirtConnection] 
(Thread-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:14:21,400 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Found NFS storage pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89] in 
libvirt, continuing.
   2022-10-18 20:14:21,400 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP 
   2022-10-18 20:14:21,401 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing while with timeout : 60000
   2022-10-18 20:14:21,930 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Execution is successful.
   2022-10-18 20:14:21,930 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) The command 
(/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP ), to the pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89], has the 
result [null].
   2022-10-18 20:14:42,073 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/network/security_group.py 
get_rule_logs_for_vms 
   2022-10-18 20:14:42,074 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing while with timeout : 1800000
   2022-10-18 20:14:42,202 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Execution is successful.
   2022-10-18 20:14:42,202 DEBUG [kvm.resource.LibvirtConnection] 
(UgentTask-5:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:14:42,223 DEBUG [cloud.agent.Agent] (UgentTask-5:null) 
(logid:) Sending ping: Seq 1-1591:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 
11, 
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{"i-2-38-VM":["38","3"],"i-2-37-VM":["37","3"],"i-2-27-VM":["27","9"],"i-2-23-VM":["23","12"],"i-2-19-VM":["19","11"],"i-2-31-VM":["31","6"],"i-2-35-VM":["35","5"],"i-2-29-VM":["29","6"],"i-2-36-VM":["36","3"],"i-2-28-VM":["28","8"]},"_hostVmStateReport":{"s-43-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-27-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-23-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-19-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-31-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-35-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-36-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-38-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-37-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"r-32-VM":{"state":"PowerOn","host":"K
 
VMHOSTNAME"},"i-2-29-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-28-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"v-11-VM":{"state":"PowerOn","host":"KVMHOSTNAME"}},"_gatewayAccessible":"true","_vnetAccessible":"true","hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:14:42,266 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) 
(logid:a8c0b95d) Received response: Seq 1-1591:  { Ans: , MgmtId: 2619780474, 
via: 1, Ver: v1, Flags: 100010, 
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"},"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:15:04,634 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-3:null) (logid:a77d7b60) Processing command: 
com.cloud.agent.api.GetHostStatsCommand
   2022-10-18 20:15:05,281 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-4:null) (logid:5321060e) Processing command: 
com.cloud.agent.api.GetVmStatsCommand
   2022-10-18 20:15:05,281 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:5321060e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:05,302 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:5321060e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:05,324 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:5321060e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:05,345 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:5321060e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:05,355 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:5321060e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:05,375 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:5321060e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:05,397 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:5321060e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:05,419 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:5321060e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:05,429 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:5321060e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:05,439 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:5321060e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:10,335 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:c76bb337) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:15:10,335 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:c76bb337) Trying to fetch storage pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 from libvirt
   2022-10-18 20:15:10,335 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:c76bb337) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:10,349 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:c76bb337) Asking libvirt to refresh 
storage pool ff9a58d8-fb77-49c8-92d1-7c82fc456297
   2022-10-18 20:15:10,350 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:c76bb337) Successfully refreshed pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 Capacity: (1,6853 TB) 1853047648256 Used: 
(5,96 GB) 6402723840 Available: (1,6795 TB) 1846644924416
   2022-10-18 20:15:10,405 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:c76bb337) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:15:10,405 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:c76bb337) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:15:10,405 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:c76bb337) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:15:10,419 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:c76bb337) Asking libvirt to refresh 
storage pool 81ffca3a-9775-375d-a1c0-9504c0ec3d89
   2022-10-18 20:15:20,253 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:c76bb337) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(357,19 GB) 383527157760 Available: (513,67 GB) 551554121728
   2022-10-18 20:15:21,930 DEBUG [kvm.resource.LibvirtConnection] 
(Thread-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:15:21,943 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Found NFS storage pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89] in 
libvirt, continuing.
   2022-10-18 20:15:21,943 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP 
   2022-10-18 20:15:21,944 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing while with timeout : 60000
   2022-10-18 20:15:22,506 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Execution is successful.
   2022-10-18 20:15:22,506 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) The command 
(/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP ), to the pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89], has the 
result [null].
   2022-10-18 20:15:42,074 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/network/security_group.py 
get_rule_logs_for_vms 
   2022-10-18 20:15:42,075 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing while with timeout : 1800000
   2022-10-18 20:15:42,199 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Execution is successful.
   2022-10-18 20:15:42,199 DEBUG [kvm.resource.LibvirtConnection] 
(UgentTask-5:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:15:42,219 DEBUG [cloud.agent.Agent] (UgentTask-5:null) 
(logid:) Sending ping: Seq 1-1592:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 
11, 
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{"i-2-38-VM":["38","3"],"i-2-37-VM":["37","3"],"i-2-27-VM":["27","9"],"i-2-23-VM":["23","12"],"i-2-19-VM":["19","11"],"i-2-31-VM":["31","6"],"i-2-35-VM":["35","5"],"i-2-29-VM":["29","6"],"i-2-36-VM":["36","3"],"i-2-28-VM":["28","8"]},"_hostVmStateReport":{"s-43-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-27-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-23-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-19-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-31-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-35-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-36-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-38-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-37-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"r-32-VM":{"state":"PowerOn","host":"K
 
VMHOSTNAME"},"i-2-29-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-28-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"v-11-VM":{"state":"PowerOn","host":"KVMHOSTNAME"}},"_gatewayAccessible":"true","_vnetAccessible":"true","hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:15:42,260 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) 
(logid:a8c0b95d) Received response: Seq 1-1592:  { Ans: , MgmtId: 2619780474, 
via: 1, Ver: v1, Flags: 100010, 
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"},"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:16:04,692 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-3:null) (logid:ee561336) Processing command: 
com.cloud.agent.api.GetHostStatsCommand
   2022-10-18 20:16:07,734 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-4:null) (logid:11593dfb) Processing command: 
com.cloud.agent.api.GetVmStatsCommand
   2022-10-18 20:16:07,734 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:11593dfb) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:07,755 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:11593dfb) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:07,776 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:11593dfb) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:07,797 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:11593dfb) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:07,818 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:11593dfb) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:07,827 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:11593dfb) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:07,836 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:11593dfb) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:07,857 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:11593dfb) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:07,877 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:11593dfb) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:07,886 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:11593dfb) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:20,384 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:582cef47) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:16:20,384 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:582cef47) Trying to fetch storage pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 from libvirt
   2022-10-18 20:16:20,384 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:582cef47) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:20,398 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:582cef47) Asking libvirt to refresh 
storage pool ff9a58d8-fb77-49c8-92d1-7c82fc456297
   2022-10-18 20:16:20,399 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:582cef47) Successfully refreshed pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 Capacity: (1,6853 TB) 1853047648256 Used: 
(5,96 GB) 6402756608 Available: (1,6795 TB) 1846644891648
   2022-10-18 20:16:20,455 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:582cef47) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:16:20,455 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:582cef47) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:16:20,455 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:582cef47) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:16:20,457 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:582cef47) Asking libvirt to refresh 
storage pool 81ffca3a-9775-375d-a1c0-9504c0ec3d89
   2022-10-18 20:16:22,506 DEBUG [kvm.resource.LibvirtConnection] 
(Thread-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:16:32,834 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Found NFS storage pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89] in 
libvirt, continuing.
   2022-10-18 20:16:32,834 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP 
   2022-10-18 20:16:32,835 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:582cef47) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(357,90 GB) 384290521088 Available: (512,96 GB) 550790758400
   2022-10-18 20:16:32,835 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing while with timeout : 60000
   2022-10-18 20:16:33,315 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Execution is successful.
   2022-10-18 20:16:33,316 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) The command 
(/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP ), to the pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89], has the 
result [null].
   2022-10-18 20:16:42,074 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/network/security_group.py 
get_rule_logs_for_vms 
   2022-10-18 20:16:42,075 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing while with timeout : 1800000
   2022-10-18 20:16:42,195 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Execution is successful.
   2022-10-18 20:16:42,195 DEBUG [kvm.resource.LibvirtConnection] 
(UgentTask-5:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:16:42,214 DEBUG [cloud.agent.Agent] (UgentTask-5:null) 
(logid:) Sending ping: Seq 1-1593:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 
11, 
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{"i-2-38-VM":["38","3"],"i-2-37-VM":["37","3"],"i-2-27-VM":["27","9"],"i-2-23-VM":["23","12"],"i-2-19-VM":["19","11"],"i-2-31-VM":["31","6"],"i-2-35-VM":["35","5"],"i-2-29-VM":["29","6"],"i-2-36-VM":["36","3"],"i-2-28-VM":["28","8"]},"_hostVmStateReport":{"s-43-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-27-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-23-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-19-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-31-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-35-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-36-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-38-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-37-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"r-32-VM":{"state":"PowerOn","host":"K
 
VMHOSTNAME"},"i-2-29-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-28-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"v-11-VM":{"state":"PowerOn","host":"KVMHOSTNAME"}},"_gatewayAccessible":"true","_vnetAccessible":"true","hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:16:42,250 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) 
(logid:a8c0b95d) Received response: Seq 1-1593:  { Ans: , MgmtId: 2619780474, 
via: 1, Ver: v1, Flags: 100010, 
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"},"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:17:04,748 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-3:null) (logid:d8b75b0f) Processing command: 
com.cloud.agent.api.GetHostStatsCommand
   2022-10-18 20:17:07,984 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-4:null) (logid:54100322) Processing command: 
com.cloud.agent.api.GetVmStatsCommand
   2022-10-18 20:17:07,985 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:54100322) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:08,005 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:54100322) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:08,027 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:54100322) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:08,048 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:54100322) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:08,070 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:54100322) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:08,080 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:54100322) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:08,090 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:54100322) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:08,114 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:54100322) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:08,135 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:54100322) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:08,157 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:54100322) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:32,979 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:8d052b63) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:17:32,979 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:8d052b63) Trying to fetch storage pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 from libvirt
   2022-10-18 20:17:32,979 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:8d052b63) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:32,992 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:8d052b63) Asking libvirt to refresh 
storage pool ff9a58d8-fb77-49c8-92d1-7c82fc456297
   2022-10-18 20:17:32,993 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:8d052b63) Successfully refreshed pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 Capacity: (1,6853 TB) 1853047648256 Used: 
(5,96 GB) 6402772992 Available: (1,6795 TB) 1846644875264
   2022-10-18 20:17:33,051 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:8d052b63) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:17:33,051 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:8d052b63) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:17:33,051 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:8d052b63) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:17:33,065 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:8d052b63) Asking libvirt to refresh 
storage pool 81ffca3a-9775-375d-a1c0-9504c0ec3d89
   2022-10-18 20:17:33,316 DEBUG [kvm.resource.LibvirtConnection] 
(Thread-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:17:40,359 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Found NFS storage pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89] in 
libvirt, continuing.
   2022-10-18 20:17:40,359 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP 
   2022-10-18 20:17:40,360 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:8d052b63) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(358,56 GB) 385002504192 Available: (512,30 GB) 550078775296
   2022-10-18 20:17:40,360 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing while with timeout : 60000
   2022-10-18 20:17:40,815 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Execution is successful.
   2022-10-18 20:17:40,816 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) The command 
(/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP ), to the pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89], has the 
result [null].
   2022-10-18 20:17:42,074 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/network/security_group.py 
get_rule_logs_for_vms 
   2022-10-18 20:17:42,075 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing while with timeout : 1800000
   2022-10-18 20:17:42,198 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Execution is successful.
   2022-10-18 20:17:42,198 DEBUG [kvm.resource.LibvirtConnection] 
(UgentTask-5:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:17:42,217 DEBUG [cloud.agent.Agent] (UgentTask-5:null) 
(logid:) Sending ping: Seq 1-1594:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 
11, 
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{"i-2-38-VM":["38","3"],"i-2-37-VM":["37","3"],"i-2-27-VM":["27","9"],"i-2-23-VM":["23","12"],"i-2-19-VM":["19","11"],"i-2-31-VM":["31","6"],"i-2-35-VM":["35","5"],"i-2-29-VM":["29","6"],"i-2-36-VM":["36","3"],"i-2-28-VM":["28","8"]},"_hostVmStateReport":{"s-43-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-27-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-23-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-19-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-31-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-35-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-36-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-38-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-37-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"r-32-VM":{"state":"PowerOn","host":"K
 
VMHOSTNAME"},"i-2-29-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-28-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"v-11-VM":{"state":"PowerOn","host":"KVMHOSTNAME"}},"_gatewayAccessible":"true","_vnetAccessible":"true","hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:17:42,258 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) 
(logid:a8c0b95d) Received response: Seq 1-1594:  { Ans: , MgmtId: 2619780474, 
via: 1, Ver: v1, Flags: 100010, 
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"},"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:18:04,803 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-3:null) (logid:63303b0b) Processing command: 
com.cloud.agent.api.GetHostStatsCommand
   2022-10-18 20:18:08,257 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-4:null) (logid:0f2b3e7e) Processing command: 
com.cloud.agent.api.GetVmStatsCommand
   2022-10-18 20:18:08,257 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:0f2b3e7e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:08,279 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:0f2b3e7e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:08,287 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:0f2b3e7e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:08,308 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:0f2b3e7e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:08,316 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:0f2b3e7e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:08,325 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:0f2b3e7e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:08,345 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:0f2b3e7e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:08,354 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:0f2b3e7e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:08,374 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:0f2b3e7e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:08,383 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:0f2b3e7e) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:40,492 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:7b99468f) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:18:40,492 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:7b99468f) Trying to fetch storage pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 from libvirt
   2022-10-18 20:18:40,492 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:7b99468f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:40,506 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:7b99468f) Asking libvirt to refresh 
storage pool ff9a58d8-fb77-49c8-92d1-7c82fc456297
   2022-10-18 20:18:40,507 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:7b99468f) Successfully refreshed pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 Capacity: (1,6853 TB) 1853047648256 Used: 
(5,96 GB) 6402797568 Available: (1,6795 TB) 1846644850688
   2022-10-18 20:18:40,565 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:7b99468f) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:18:40,565 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:7b99468f) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:18:40,565 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:7b99468f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:18:40,579 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:7b99468f) Asking libvirt to refresh 
storage pool 81ffca3a-9775-375d-a1c0-9504c0ec3d89
   2022-10-18 20:18:40,816 DEBUG [kvm.resource.LibvirtConnection] 
(Thread-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:18:42,074 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/network/security_group.py 
get_rule_logs_for_vms 
   2022-10-18 20:18:42,075 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing while with timeout : 1800000
   2022-10-18 20:18:42,194 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Execution is successful.
   2022-10-18 20:18:42,194 DEBUG [kvm.resource.LibvirtConnection] 
(UgentTask-5:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:18:42,215 DEBUG [cloud.agent.Agent] (UgentTask-5:null) 
(logid:) Sending ping: Seq 1-1595:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 
11, 
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{"i-2-38-VM":["38","3"],"i-2-37-VM":["37","3"],"i-2-27-VM":["27","9"],"i-2-23-VM":["23","12"],"i-2-19-VM":["19","11"],"i-2-31-VM":["31","6"],"i-2-35-VM":["35","5"],"i-2-29-VM":["29","6"],"i-2-36-VM":["36","3"],"i-2-28-VM":["28","8"]},"_hostVmStateReport":{"s-43-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-27-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-23-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-19-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-31-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-35-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-36-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-38-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-37-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"r-32-VM":{"state":"PowerOn","host":"K
 
VMHOSTNAME"},"i-2-29-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-28-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"v-11-VM":{"state":"PowerOn","host":"KVMHOSTNAME"}},"_gatewayAccessible":"true","_vnetAccessible":"true","hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:18:42,296 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) 
(logid:a8c0b95d) Received response: Seq 1-1595:  { Ans: , MgmtId: 2619780474, 
via: 1, Ver: v1, Flags: 100010, 
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"},"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:18:49,154 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Found NFS storage pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89] in 
libvirt, continuing.
   2022-10-18 20:18:49,154 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP 
   2022-10-18 20:18:49,154 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:7b99468f) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,24 GB) 385731264512 Available: (511,62 GB) 549350014976
   2022-10-18 20:18:49,155 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing while with timeout : 60000
   2022-10-18 20:18:49,699 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Execution is successful.
   2022-10-18 20:18:49,700 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) The command 
(/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP ), to the pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89], has the 
result [null].
   2022-10-18 20:19:04,860 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-3:null) (logid:0f67a2e7) Processing command: 
com.cloud.agent.api.GetHostStatsCommand
   2022-10-18 20:19:08,483 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-4:null) (logid:26fb333f) Processing command: 
com.cloud.agent.api.GetVmStatsCommand
   2022-10-18 20:19:08,483 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:26fb333f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:08,505 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:26fb333f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:08,526 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:26fb333f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:08,535 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:26fb333f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:08,544 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:26fb333f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:08,564 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:26fb333f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:08,579 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:26fb333f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:08,602 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:26fb333f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:08,610 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:26fb333f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:08,619 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:26fb333f) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:40,499 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:f0185ee6) Request:Seq 
1-1590615093391918320:  { Cmd , MgmtId: 2619780474, via: 1, Ver: v1, Flags: 
100011, 
[{"com.cloud.agent.api.routing.GetRouterMonitorResultsCommand":{"performFreshChecks":"false","validateBasicTestsOnly":"true","accessDetails":{"router.ip":"169.254.158.98","router.name":"r-32-VM"},"wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:19:40,499 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:f0185ee6) Processing command: 
com.cloud.agent.api.routing.GetRouterMonitorResultsCommand
   2022-10-18 20:19:40,499 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-1:null) (logid:f0185ee6) Executing: 
/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh 
filesystem_writable_check.py 169.254.158.98 
   2022-10-18 20:19:40,500 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-1:null) (logid:f0185ee6) Executing while with timeout : 
1800000
   2022-10-18 20:19:40,701 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-1:null) (logid:f0185ee6) Execution is successful.
   2022-10-18 20:19:40,701 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-1:null) (logid:f0185ee6) Executing script in VR: 
filesystem_writable_check.py
   2022-10-18 20:19:40,701 DEBUG 
[resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-1:null) 
(logid:f0185ee6) Router connectivity and file system writable check passed
   2022-10-18 20:19:40,702 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:f0185ee6) Seq 1-1590615093391918320:  { 
Ans: , MgmtId: 2619780474, via: 1, Ver: v1, Flags: 10, 
[{"com.cloud.agent.api.routing.GetRouterMonitorResultsAnswer":{"monitoringResults":"success","result":"true","details":"success","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:19:40,749 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Request:Seq 
1-1590615093391918321:  { Cmd , MgmtId: 2619780474, via: 1, Ver: v1, Flags: 
100011, 
[{"com.cloud.agent.api.routing.SetMonitorServiceCommand":{"healthChecksConfig":{"gateways":"gatewaysIps=41.72.146.241
 169.254.0.1 
","portForwarding":"","systemThresholds":"minDiskNeeded=100.0,maxCpuUsage=100.0,maxMemoryUsage=100.0;","haproxyData":"","virtualMachines":"vmName=RocketChat,macAddress=1e:00:e7:00:00:03,ip=41.72.146.244,dhcp=true,dns=true;vmName=HMA,macAddress=1e:00:4a:00:00:05,ip=41.72.146.246,dhcp=true,dns=true;vmName=Mabaruli,macAddress=1e:00:38:00:00:06,ip=41.72.146.247,dhcp=true,dns=true;vmName=Confidente,macAddress=1e:00:f1:00:00:07,ip=41.72.146.248,dhcp=true,dns=true;vmName=NAMFISA,macAddress=1e:00:f0:00:00:08,ip=41.72.146.249,dhcp=true,dns=true;vmName=CKNam,macAddress=1e:00:66:00:00:0a,ip=41.72.146.251,dhcp=true,dns=true;vmName=SSConsultings,macAddress=1e:00:59:00:00:04,ip
 
=41.72.146.245,dhcp=true,dns=true;vmName=Benade,macAddress=1e:00:84:00:00:0b,ip=41.72.146.252,dhcp=true,dns=true;vmName=RTC,macAddress=1e:00:ca:00:00:0c,ip=41.72.146.253,dhcp=true,dns=true;vmName=Nacdo,macAddress=1e:00:9b:00:00:0d,ip=41.72.146.254,dhcp=true,dns=true;","routerVersion":"templateVersion=Cloudstack
 Release 4.17.0 Mon 02 May 2022 04:00:10 PM 
UTC,scriptsVersion=45795a9522a88a70d2640809db5ba452
   
"},"reconfigureAfterUpdate":"true","deleteFromProcessedCache":"true","accessDetails":{"router.health.checks.enabled":"true","router.ip":"169.254.158.98","router.name":"r-32-VM","router.health.checks.advanced.interval":"10","router.health.checks.basic.interval":"3","router.health.checks.excluded":""},"wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:19:40,749 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Processing command: 
com.cloud.agent.api.routing.SetMonitorServiceCommand
   2022-10-18 20:19:40,749 DEBUG 
[resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) 
(logid:f0185ee6) Transforming 
com.cloud.agent.api.routing.SetMonitorServiceCommand to ConfigItems
   2022-10-18 20:19:40,749 DEBUG 
[virtualnetwork.facade.AbstractConfigItemFacade] (agentRequest-Handler-2:null) 
(logid:f0185ee6) Transformed filename: monitor_service.json to: 
monitor_service.json.7d87d541-deef-42c7-96bf-b8f04ff95a93
   2022-10-18 20:19:40,749 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Creating file in VR, with ip: 
169.254.158.98, file: monitor_service.json.7d87d541-deef-42c7-96bf-b8f04ff95a93
   2022-10-18 20:19:40,983 DEBUG 
[resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) 
(logid:f0185ee6) Processing FileConfigItem, copying 1353 characters to 
monitor_service.json.7d87d541-deef-42c7-96bf-b8f04ff95a93 took 234ms
   2022-10-18 20:19:40,984 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Executing: 
/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh 
update_config.py 169.254.158.98 
monitor_service.json.7d87d541-deef-42c7-96bf-b8f04ff95a93 false 
   2022-10-18 20:19:40,985 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Executing while with timeout : 
600000
   2022-10-18 20:19:41,453 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Execution is successful.
   2022-10-18 20:19:41,453 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Executing script in VR: 
update_config.py
   2022-10-18 20:19:41,453 DEBUG 
[resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) 
(logid:f0185ee6) Processing ScriptConfigItem, executing update_config.py 
monitor_service.json.7d87d541-deef-42c7-96bf-b8f04ff95a93 false took 469ms
   2022-10-18 20:19:41,453 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Executing: 
/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh configure.py 
169.254.158.98 monitor_service.json 
   2022-10-18 20:19:41,454 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Executing while with timeout : 
600000
   2022-10-18 20:19:41,762 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Execution is successful.
   2022-10-18 20:19:41,762 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Executing script in VR: 
configure.py
   2022-10-18 20:19:41,762 DEBUG 
[resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) 
(logid:f0185ee6) Processing ScriptConfigItem, executing configure.py 
monitor_service.json took 309ms
   2022-10-18 20:19:41,762 WARN  
[resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) 
(logid:f0185ee6) Expected 1 answers while executing SetMonitorServiceCommand 
but received 3
   2022-10-18 20:19:41,763 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:f0185ee6) Seq 1-1590615093391918321:  { 
Ans: , MgmtId: 2619780474, via: 1, Ver: v1, Flags: 10, 
[{"com.cloud.agent.api.routing.GroupAnswer":{"results":["null - success: 
Creating file in VR, with ip: 169.254.158.98, file: 
monitor_service.json.7d87d541-deef-42c7-96bf-b8f04ff95a93","null - success: 
","null - success: 
"],"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
   2022-10-18 20:19:41,819 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-3:null) (logid:667daea7) Request:Seq 
1-1590615093391918322:  { Cmd , MgmtId: 2619780474, via: 1, Ver: v1, Flags: 
100011, 
[{"com.cloud.agent.api.routing.GetRouterMonitorResultsCommand":{"performFreshChecks":"false","validateBasicTestsOnly":"false","accessDetails":{"router.ip":"169.254.158.98","router.name":"r-32-VM"},"wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:19:41,819 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-3:null) (logid:667daea7) Processing command: 
com.cloud.agent.api.routing.GetRouterMonitorResultsCommand
   2022-10-18 20:19:41,819 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-3:null) (logid:667daea7) Executing: 
/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh 
filesystem_writable_check.py 169.254.158.98 
   2022-10-18 20:19:41,820 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-3:null) (logid:667daea7) Executing while with timeout : 
1800000
   2022-10-18 20:19:41,957 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-3:null) (logid:667daea7) Execution is successful.
   2022-10-18 20:19:41,957 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-3:null) (logid:667daea7) Executing script in VR: 
filesystem_writable_check.py
   2022-10-18 20:19:41,957 DEBUG 
[resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-3:null) 
(logid:667daea7) Router connectivity and file system writable check passed
   2022-10-18 20:19:41,957 INFO  
[resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-3:null) 
(logid:667daea7) Fetching health check result for 169.254.158.98 and executing 
fresh checks: false
   2022-10-18 20:19:41,957 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-3:null) (logid:667daea7) Executing: 
/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh 
getRouterMonitorResults.sh 169.254.158.98 false 
   2022-10-18 20:19:41,958 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-3:null) (logid:667daea7) Executing while with timeout : 
1800000
   2022-10-18 20:19:42,074 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/network/security_group.py 
get_rule_logs_for_vms 
   2022-10-18 20:19:42,075 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing while with timeout : 1800000
   2022-10-18 20:19:42,084 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-3:null) (logid:667daea7) Execution is successful.
   2022-10-18 20:19:42,084 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-3:null) (logid:667daea7) Executing script in VR: 
getRouterMonitorResults.sh
   2022-10-18 20:19:42,086 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-3:null) (logid:667daea7) Seq 1-1590615093391918322:  { 
Ans: , MgmtId: 2619780474, via: 1, Ver: v1, Flags: 10, 
[{"com.cloud.agent.api.routing.GetRouterMonitorResultsAnswer":{"failingChecks":[],"monitoringResults":"{"basic":{"lastRun":
 {"duration": "11.4090528488", "start": "2022-10-18 18:18:01.684931", "end": 
"2022-10-18 18:18:13.093984"}, "disk_space_check.py": {"lastRunDuration": 
"15.7380104065", "lastUpdate": "1666117093042", "message": "Sufficient free 
space is 2019 MB", "success": "true"}, "memory_usage_check.py": 
{"lastRunDuration": "27.8658866882", "lastUpdate": "1666117092998", "message": 
"Memory Usage within limits with current at 30.9631%", "success": "true"}, 
"ssh.service": {"lastRunDuration": "15.6829357147", "lastUpdate": 
"1666117081686", "message": "service is running", "success": "true"}, 
"dhcp.service": {"lastRunDuration": "7.36212730408", "lastUpdate": 
"1666117081686", "message": "service is ru
 nning", "success": "true"}, "gateways_check.py": {"lastRunDuration": 
"8044.89517212", "lastUpdate": "1666117084953", "message": "All 2 gateways are 
reachable via ping", "success": "true"}, "cpu_usage_check.py": 
{"lastRunDuration": "3203.67717743", "lastUpdate": "1666117081749", "message": 
"CPU Usage within limits with current at 0.3%", "success": "true"}, 
"router_version_check.py": {"lastRunDuration": "16.2389278412", "lastUpdate": 
"1666117093077", "message": "Template and scripts version match successful", 
"success": "true"}, "webserver.service": {"lastRunDuration": "11.5239620209", 
"lastUpdate": "1666117081686", "message": "service is running", "success": 
"true"}},"advanced":{"lastRun": {"duration": "0.173095941544", "start": 
"2022-10-18 18:10:01.507455", "end": "2022-10-18 18:10:01.680551"}, 
"haproxy_check.py": {"lastRunDuration": "16.4968967438", "lastUpdate": 
"1666116601538", "message": "No data provided to check, skipping", "success": 
"true"}, "dhcp_check.py": {"lastRunDuratio
 n": "16.9341564178", "lastUpdate": "1666116601508", "message": "All 10 VMs are 
present in dhcphosts.txt", "success": "true"}, "dns_check.py": 
{"lastRunDuration": "15.9339904785", "lastUpdate": "1666116601613", "message": 
"All 10 VMs are present in /etc/hosts", "success": "true"}, 
"iptables_check.py": {"lastRunDuration": "19.2470550537", "lastUpdate": 
"1666116601645", "message": "No portforwarding rules provided to check, 
skipping", "success": 
"true"}}}","result":"true","details":"{"basic":{"lastRun": {"duration": 
"11.4090528488", "start": "2022-10-18 18:18:01.684931", "end": "2022-10-18 
18:18:13.093984"}, "disk_space_check.py": {"lastRunDuration": "15.7380104065", 
"lastUpdate": "1666117093042", "message": "Sufficient free space is 2019 MB", 
"success": "true"}, "memory_usage_check.py": {"lastRunDuration": 
"27.8658866882", "lastUpdate": "1666117092998", "message": "Memory Usage within 
limits with current at 30.9631%", "success": "true"}, "ssh.service": 
{"lastRunDuration": "15.68293571
 47", "lastUpdate": "1666117081686", "message": "service is running", 
"success": "true"}, "dhcp.service": {"lastRunDuration": "7.36212730408", 
"lastUpdate": "1666117081686", "message": "service is running", "success": 
"true"}, "gateways_check.py": {"lastRunDuration": "8044.89517212", 
"lastUpdate": "1666117084953", "message": "All 2 gateways are reachable via 
ping", "success": "true"}, "cpu_usage_check.py": {"lastRunDuration": 
"3203.67717743", "lastUpdate": "1666117081749", "message": "CPU Usage within 
limits with current at 0.3%", "success": "true"}, "router_version_check.py": 
{"lastRunDuration": "16.2389278412", "lastUpdate": "1666117093077", "message": 
"Template and scripts version match successful", "success": "true"}, 
"webserver.service": {"lastRunDuration": "11.5239620209", "lastUpdate": 
"1666117081686", "message": "service is running", "success": 
"true"}},"advanced":{"lastRun": {"duration": "0.173095941544", "start": 
"2022-10-18 18:10:01.507455", "end": "2022-10-18 18:10:01.680
 551"}, "haproxy_check.py": {"lastRunDuration": "16.4968967438", "lastUpdate": 
"1666116601538", "message": "No data provided to check, skipping", "success": 
"true"}, "dhcp_check.py": {"lastRunDuration": "16.9341564178", "lastUpdate": 
"1666116601508", "message": "All 10 VMs are present in dhcphosts.txt", 
"success": "true"}, "dns_check.py": {"lastRunDuration": "15.9339904785", 
"lastUpdate": "1666116601613", "message": "All 10 VMs are present in 
/etc/hosts", "success": "true"}, "iptables_check.py": {"lastRunDuration": 
"19.2470550537", "lastUpdate": "1666116601645", "message": "No portforwarding 
rules provided to check, skipping", "success": 
"true"}}}","wait":"0","bypassHostMaintenance":"false"}}] }
   2022-10-18 20:19:42,195 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Execution is successful.
   2022-10-18 20:19:42,195 DEBUG [kvm.resource.LibvirtConnection] 
(UgentTask-5:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:19:42,214 DEBUG [cloud.agent.Agent] (UgentTask-5:null) 
(logid:) Sending ping: Seq 1-1596:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 
11, 
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{"i-2-38-VM":["38","3"],"i-2-37-VM":["37","3"],"i-2-27-VM":["27","9"],"i-2-23-VM":["23","12"],"i-2-19-VM":["19","11"],"i-2-31-VM":["31","6"],"i-2-35-VM":["35","5"],"i-2-29-VM":["29","6"],"i-2-36-VM":["36","3"],"i-2-28-VM":["28","8"]},"_hostVmStateReport":{"s-43-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-27-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-23-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-19-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-31-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-35-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-36-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-38-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-37-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"r-32-VM":{"state":"PowerOn","host":"K
 
VMHOSTNAME"},"i-2-29-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-28-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"v-11-VM":{"state":"PowerOn","host":"KVMHOSTNAME"}},"_gatewayAccessible":"true","_vnetAccessible":"true","hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:19:42,299 DEBUG [cloud.agent.Agent] (Agent-Handler-3:null) 
(logid:a8c0b95d) Received response: Seq 1-1596:  { Ans: , MgmtId: 2619780474, 
via: 1, Ver: v1, Flags: 100010, 
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"},"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:19:49,288 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-4:null) (logid:834f7792) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:19:49,288 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-4:null) (logid:834f7792) Trying to fetch storage pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 from libvirt
   2022-10-18 20:19:49,288 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:834f7792) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:49,302 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-4:null) (logid:834f7792) Asking libvirt to refresh 
storage pool ff9a58d8-fb77-49c8-92d1-7c82fc456297
   2022-10-18 20:19:49,303 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-4:null) (logid:834f7792) Successfully refreshed pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 Capacity: (1,6853 TB) 1853047648256 Used: 
(5,96 GB) 6402985984 Available: (1,6795 TB) 1846644662272
   2022-10-18 20:19:49,399 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:834f7792) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:19:49,399 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:834f7792) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:19:49,399 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:834f7792) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:49,412 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:834f7792) Asking libvirt to refresh 
storage pool 81ffca3a-9775-375d-a1c0-9504c0ec3d89
   2022-10-18 20:19:49,700 DEBUG [kvm.resource.LibvirtConnection] 
(Thread-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:19:55,524 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:cd004f6b) Processing command: 
com.cloud.agent.api.GetVolumeStatsCommand
   2022-10-18 20:19:55,524 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:55,536 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:cd004f6b) Trying to fetch storage pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 from libvirt
   2022-10-18 20:19:55,536 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:55,551 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:cd004f6b) Successfully refreshed pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 Capacity: (1,6853 TB) 1853047648256 Used: 
(5,96 GB) 6402985984 Available: (1,6795 TB) 1846644662272
   2022-10-18 20:19:55,552 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:cd004f6b) Trying to fetch storage pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 from libvirt
   2022-10-18 20:19:55,552 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:55,566 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:cd004f6b) Successfully refreshed pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 Capacity: (1,6853 TB) 1853047648256 Used: 
(5,96 GB) 6402985984 Available: (1,6795 TB) 1846644662272
   2022-10-18 20:19:55,568 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:cd004f6b) Trying to fetch storage pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 from libvirt
   2022-10-18 20:19:55,568 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:55,570 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-2:null) (logid:cd004f6b) Successfully refreshed pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 Capacity: (1,6853 TB) 1853047648256 Used: 
(5,96 GB) 6402985984 Available: (1,6795 TB) 1846644662272
   2022-10-18 20:19:55,625 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Processing command: 
com.cloud.agent.api.GetVolumeStatsCommand
   2022-10-18 20:19:55,625 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:55,638 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:19:55,638 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:19:59,296 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Found NFS storage pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89] in 
libvirt, continuing.
   2022-10-18 20:19:59,297 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP 
   2022-10-18 20:19:59,297 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:834f7792) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,93 GB) 386472607744 Available: (510,93 GB) 548608671744
   2022-10-18 20:19:59,297 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing while with timeout : 60000
   2022-10-18 20:19:59,298 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,93 GB) 386472607744 Available: (510,93 GB) 548608671744
   2022-10-18 20:19:59,761 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Execution is successful.
   2022-10-18 20:19:59,761 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) The command 
(/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP ), to the pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89], has the 
result [null].
   2022-10-18 20:20:00,310 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:20:00,310 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:00,325 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,93 GB) 386472607744 Available: (510,93 GB) 548608671744
   2022-10-18 20:20:01,690 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:20:01,690 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:01,705 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,93 GB) 386472607744 Available: (510,93 GB) 548608671744
   2022-10-18 20:20:04,876 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-4:null) (logid:0f4c2a79) Processing command: 
com.cloud.agent.api.GetHostStatsCommand
   2022-10-18 20:20:05,142 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:20:05,142 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:05,156 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,93 GB) 386472607744 Available: (510,93 GB) 548608671744
   2022-10-18 20:20:08,038 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:20:08,038 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:08,052 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,93 GB) 386472607744 Available: (510,93 GB) 548608671744
   2022-10-18 20:20:08,715 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:a7d8ff1a) Processing command: 
com.cloud.agent.api.GetVmStatsCommand
   2022-10-18 20:20:08,715 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:a7d8ff1a) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:08,737 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:a7d8ff1a) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:08,745 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:a7d8ff1a) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:08,767 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:a7d8ff1a) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:08,789 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:a7d8ff1a) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:08,810 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:a7d8ff1a) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:08,819 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:a7d8ff1a) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:08,842 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:a7d8ff1a) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:08,850 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:a7d8ff1a) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:08,872 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-2:null) (logid:a7d8ff1a) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:11,014 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:20:11,014 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:11,028 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,93 GB) 386472607744 Available: (510,93 GB) 548608671744
   2022-10-18 20:20:12,946 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:20:12,947 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:12,961 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,93 GB) 386472607744 Available: (510,93 GB) 548608671744
   2022-10-18 20:20:15,153 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:20:15,153 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:15,167 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,93 GB) 386472607744 Available: (510,93 GB) 548608671744
   2022-10-18 20:20:17,449 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:20:17,449 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:17,464 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,93 GB) 386472607744 Available: (510,93 GB) 548608671744
   2022-10-18 20:20:21,103 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:20:21,103 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:21,117 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-3:null) (logid:cd004f6b) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(359,93 GB) 386472607744 Available: (510,93 GB) 548608671744
   2022-10-18 20:20:42,074 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/network/security_group.py 
get_rule_logs_for_vms 
   2022-10-18 20:20:42,075 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Executing while with timeout : 1800000
   2022-10-18 20:20:42,204 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) (logid:) Execution is successful.
   2022-10-18 20:20:42,204 DEBUG [kvm.resource.LibvirtConnection] 
(UgentTask-5:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:20:42,224 DEBUG [cloud.agent.Agent] (UgentTask-5:null) 
(logid:) Sending ping: Seq 1-1597:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 
11, 
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{"i-2-38-VM":["38","3"],"i-2-37-VM":["37","3"],"i-2-27-VM":["27","9"],"i-2-23-VM":["23","12"],"i-2-19-VM":["19","11"],"i-2-31-VM":["31","6"],"i-2-35-VM":["35","5"],"i-2-29-VM":["29","6"],"i-2-36-VM":["36","3"],"i-2-28-VM":["28","8"]},"_hostVmStateReport":{"s-43-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-27-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-23-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-19-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-31-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-35-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-36-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-38-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-37-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"r-32-VM":{"state":"PowerOn","host":"K
 
VMHOSTNAME"},"i-2-29-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"i-2-28-VM":{"state":"PowerOn","host":"KVMHOSTNAME"},"v-11-VM":{"state":"PowerOn","host":"KVMHOSTNAME"}},"_gatewayAccessible":"true","_vnetAccessible":"true","hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:20:42,268 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null) 
(logid:b59cc776) Received response: Seq 1-1597:  { Ans: , MgmtId: 2619780474, 
via: 1, Ver: v1, Flags: 100010, 
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":"1","wait":"0","bypassHostMaintenance":"false"},"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
 }
   2022-10-18 20:20:59,403 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-1:null) (logid:df16d286) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:20:59,403 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:df16d286) Trying to fetch storage pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 from libvirt
   2022-10-18 20:20:59,403 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-1:null) (logid:df16d286) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:20:59,417 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:df16d286) Asking libvirt to refresh 
storage pool ff9a58d8-fb77-49c8-92d1-7c82fc456297
   2022-10-18 20:20:59,418 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-1:null) (logid:df16d286) Successfully refreshed pool 
ff9a58d8-fb77-49c8-92d1-7c82fc456297 Capacity: (1,6853 TB) 1853047648256 Used: 
(5,96 GB) 6403018752 Available: (1,6795 TB) 1846644629504
   2022-10-18 20:20:59,761 DEBUG [kvm.resource.LibvirtConnection] 
(Thread-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
   2022-10-18 20:20:59,774 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Found NFS storage pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89] in 
libvirt, continuing.
   2022-10-18 20:20:59,774 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing: 
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP 
   2022-10-18 20:20:59,775 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Executing while with timeout : 60000
   2022-10-18 20:20:59,813 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) Execution is successful.
   2022-10-18 20:20:59,813 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) 
(logid:) The command 
(/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 
MANAGEMENTHOSTIP -p /mnt/primary -m /mnt/81ffca3a-9775-375d-a1c0-9504c0ec3d89 
-h KVMHOSTIP ), to the pool [81ffca3a-9775-375d-a1c0-9504c0ec3d89], has the 
result [null].
   2022-10-18 20:21:01,116 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-4:null) (logid:df16d286) Processing command: 
com.cloud.agent.api.GetStorageStatsCommand
   2022-10-18 20:21:01,116 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-4:null) (logid:df16d286) Trying to fetch storage pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 from libvirt
   2022-10-18 20:21:01,116 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-4:null) (logid:df16d286) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:21:01,130 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-4:null) (logid:df16d286) Asking libvirt to refresh 
storage pool 81ffca3a-9775-375d-a1c0-9504c0ec3d89
   2022-10-18 20:21:04,894 DEBUG [cloud.agent.Agent] 
(agentRequest-Handler-2:null) (logid:08cebab6) Processing command: 
com.cloud.agent.api.GetHostStatsCommand
   2022-10-18 20:21:06,498 DEBUG [kvm.storage.KVMStorageProcessor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Execution is successful.
   2022-10-18 20:21:06,582 DEBUG [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-4:null) (logid:df16d286) Successfully refreshed pool 
81ffca3a-9775-375d-a1c0-9504c0ec3d89 Capacity: (870,86 GB) 935081279488 Used: 
(355,81 GB) 382049714176 Available: (515,05 GB) 553031565312
   2022-10-18 20:21:07,047 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Attempting to remove storage 
pool 6ff3840c-b5c3-3355-8a93-5b9d5c44901b from libvirt
   2022-10-18 20:21:07,047 DEBUG [kvm.resource.LibvirtConnection] 
(agentRequest-Handler-5:null) (logid:5af967f1) Looking for libvirtd connection 
at: qemu:///system
   2022-10-18 20:21:07,060 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Storage pool 
6ff3840c-b5c3-3355-8a93-5b9d5c44901b has no corresponding secret. Not removing 
any secret.
   2022-10-18 20:21:07,104 INFO  [kvm.storage.LibvirtStorageAdaptor] 
(agentRequest-Handler-5:null) (logid:5af967f1) Storage pool 
6ff3840c-b5c3-3355-8a93-5b9d5c44901b was successfully removed from libvirt.
   ```


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscr...@cloudstack.apache.org

For queries about this service, please contact Infrastructure at:
us...@infra.apache.org