You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cloudstack.apache.org by GitBox <gi...@apache.org> on 2020/05/29 08:37:29 UTC
[GitHub] [cloudstack] ccycv opened a new issue #4118: com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool - Ceph Storage - ACS 4.13
ccycv opened a new issue #4118:
URL: https://github.com/apache/cloudstack/issues/4118
##### ISSUE TYPE
`Bug Report`
##### COMPONENT NAME
`KVM, CloudStack Agent.`
##### CLOUDSTACK VERSION
`CloudStack 4.13.0 `
##### CONFIGURATION
`Advanced Networking with Local Storage and Ceph storage RBD.`
##### OS / ENVIRONMENT
```
CentOS Linux release 7.8.2003 (Core)
qemu-kvm 1.5.3
cloudstack-agent 4.13.0.0
libvirt 4.5.0
```
##### SUMMARY
This issue started from nothing, we wanted to deploy a new VM and we started to get this error in the UI, after this we saw that the state was changed for each KVM from connected to "connecting".
From this point we started to check the logs for agent, libvirtd also on Ceph storage. We didn't' found any error on Ceph.
Cloudstack Agent Logs:
~~~
Full log : https://gist.github.com/ccycv/b026c0d4edd19ac8ef012d334dff8b84
2020-05-29 09:48:38,110 INFO [cloud.agent.AgentShell] (main:null) (logid:) Agent started
2020-05-29 09:48:38,113 INFO [cloud.agent.AgentShell] (main:null) (logid:) Implementation Version is 4.13.0.0
2020-05-29 09:48:38,115 INFO [cloud.agent.AgentShell] (main:null) (logid:) agent.properties found at /etc/cloudstack/agent/agent.properties
2020-05-29 09:48:38,131 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: guest.network.device
2020-05-29 09:48:38,131 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: workers
2020-05-29 09:48:38,131 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: private.network.device
2020-05-29 09:48:38,131 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: port
2020-05-29 09:48:38,131 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: resource
2020-05-29 09:48:38,131 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: pod
2020-05-29 09:48:38,131 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: storage.network.device
2020-05-29 09:48:38,131 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: zone
2020-05-29 09:48:38,132 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: guid
2020-05-29 09:48:38,132 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: hypervisor.type
2020-05-29 09:48:38,132 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: cluster
2020-05-29 09:48:38,132 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: public.network.device
2020-05-29 09:48:38,136 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: local.storage.uuid
2020-05-29 09:48:38,136 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: domr.scripts.dir
2020-05-29 09:48:38,136 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: keystore.passphrase
2020-05-29 09:48:38,136 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: host
2020-05-29 09:48:38,136 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Found property: LibvirtComputingResource.id
2020-05-29 09:48:38,136 INFO [cloud.agent.AgentShell] (main:null) (logid:) Defaulting to using properties file for storage
2020-05-29 09:48:38,138 INFO [cloud.agent.AgentShell] (main:null) (logid:) Defaulting to the constant time backoff algorithm
2020-05-29 09:48:38,153 INFO [cloud.utils.LogUtils] (main:null) (logid:) log4j configuration found at /etc/cloudstack/agent/log4j-cloud.xml
2020-05-29 09:48:38,167 INFO [cloud.agent.AgentShell] (main:null) (logid:) Using default Java settings for IPv6 preference for agent connection
2020-05-29 09:48:38,168 DEBUG [cloud.agent.AgentShell] (main:null) (logid:) Checking to see if agent.pid exists.
2020-05-29 09:48:38,179 DEBUG [cloud.utils.ProcessUtil] (main:null) (logid:) Executing: bash -c echo $PPID
2020-05-29 09:48:38,257 DEBUG [cloud.utils.ProcessUtil] (main:null) (logid:) Executing while with timeout : 120000
2020-05-29 09:48:38,257 DEBUG [cloud.utils.ProcessUtil] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,326 INFO [cloud.agent.Agent] (main:null) (logid:) id is 0
2020-05-29 09:48:38,327 DEBUG [cloud.resource.ServerResourceBase] (main:null) (logid:) Retrieving network interface: cloudbr0
2020-05-29 09:48:38,328 DEBUG [cloud.resource.ServerResourceBase] (main:null) (logid:) Retrieving network interface: cloudbr2
2020-05-29 09:48:38,328 DEBUG [cloud.resource.ServerResourceBase] (main:null) (logid:) Unable to get network interface for cloudbr2
2020-05-29 09:48:38,328 DEBUG [cloud.resource.ServerResourceBase] (main:null) (logid:) Retrieving network interface: cloudbr249
2020-05-29 09:48:38,328 DEBUG [cloud.resource.ServerResourceBase] (main:null) (logid:) Retrieving network interface: null
2020-05-29 09:48:38,343 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (main:null) (logid:) The router.aggregation.command.each.timeout in seconds is set to 600
2020-05-29 09:48:38,344 DEBUG [utils.script.Script] (main:null) (logid:) Looking for update_host_passwd.sh in the classpath
2020-05-29 09:48:38,344 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,344 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,344 DEBUG [utils.script.Script] (main:null) (logid:) Looking for update_host_passwd.sh
2020-05-29 09:48:38,345 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,345 DEBUG [utils.script.Script] (main:null) (logid:) Looking for update_host_passwd.sh in /usr/share/cloudstack-agent/lib/scripts/vm/hypervisor/update_host_passwd.sh
2020-05-29 09:48:38,345 DEBUG [utils.script.Script] (main:null) (logid:) Looking for update_host_passwd.sh in /usr/share/cloudstack-agent/lib/scripts/vm/update_host_passwd.sh
2020-05-29 09:48:38,345 DEBUG [utils.script.Script] (main:null) (logid:) Looking for update_host_passwd.sh in /usr/share/cloudstack-agent/lib/scripts/update_host_passwd.sh
2020-05-29 09:48:38,345 DEBUG [utils.script.Script] (main:null) (logid:) Looking for update_host_passwd.sh in /usr/share/cloudstack-agent/lib/update_host_passwd.sh
2020-05-29 09:48:38,345 DEBUG [utils.script.Script] (main:null) (logid:) Looking for update_host_passwd.sh in /usr/share/cloudstack-agent/update_host_passwd.sh
2020-05-29 09:48:38,345 DEBUG [utils.script.Script] (main:null) (logid:) Looking for update_host_passwd.sh in /usr/share/update_host_passwd.sh
2020-05-29 09:48:38,345 DEBUG [utils.script.Script] (main:null) (logid:) Looking for update_host_passwd.sh in /usr/update_host_passwd.sh
2020-05-29 09:48:38,345 DEBUG [utils.script.Script] (main:null) (logid:) Looking for update_host_passwd.sh in /update_host_passwd.sh
2020-05-29 09:48:38,346 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,346 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,346 DEBUG [utils.script.Script] (main:null) (logid:) Looking for update_host_passwd.sh in /usr/share/cloudstack-common/scripts/vm/hypervisor/update_host_passwd.sh
2020-05-29 09:48:38,346 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in the classpath
2020-05-29 09:48:38,346 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,347 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,347 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh
2020-05-29 09:48:38,347 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,347 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/lib/scripts/vm/network/vnet/modifyvlan.sh
2020-05-29 09:48:38,347 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/lib/scripts/vm/network/modifyvlan.sh
2020-05-29 09:48:38,347 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/lib/scripts/vm/modifyvlan.sh
2020-05-29 09:48:38,347 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/lib/scripts/modifyvlan.sh
2020-05-29 09:48:38,347 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/lib/modifyvlan.sh
2020-05-29 09:48:38,348 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/modifyvlan.sh
2020-05-29 09:48:38,348 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/modifyvlan.sh
2020-05-29 09:48:38,348 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/modifyvlan.sh
2020-05-29 09:48:38,348 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /modifyvlan.sh
2020-05-29 09:48:38,348 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,349 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,349 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-common/scripts/vm/network/vnet/modifyvlan.sh
2020-05-29 09:48:38,349 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in the classpath
2020-05-29 09:48:38,350 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,350 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,350 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh
2020-05-29 09:48:38,350 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,350 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in /usr/share/cloudstack-agent/lib/scripts/vm/hypervisor/kvm/versions.sh
2020-05-29 09:48:38,350 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in /usr/share/cloudstack-agent/lib/scripts/vm/hypervisor/versions.sh
2020-05-29 09:48:38,350 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in /usr/share/cloudstack-agent/lib/scripts/vm/versions.sh
2020-05-29 09:48:38,350 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in /usr/share/cloudstack-agent/lib/scripts/versions.sh
2020-05-29 09:48:38,350 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in /usr/share/cloudstack-agent/lib/versions.sh
2020-05-29 09:48:38,351 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in /usr/share/cloudstack-agent/versions.sh
2020-05-29 09:48:38,351 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in /usr/share/versions.sh
2020-05-29 09:48:38,351 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in /usr/versions.sh
2020-05-29 09:48:38,351 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in /versions.sh
2020-05-29 09:48:38,351 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,351 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,352 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/versions.sh
2020-05-29 09:48:38,352 DEBUG [utils.script.Script] (main:null) (logid:) Looking for versions.sh in /usr/share/cloudstack-common/scripts/vm/hypervisor/versions.sh
2020-05-29 09:48:38,352 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh in the classpath
2020-05-29 09:48:38,352 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,352 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,352 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh
2020-05-29 09:48:38,353 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,353 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh in /usr/share/cloudstack-agent/lib/scripts/vm/hypervisor/kvm/patch.sh
2020-05-29 09:48:38,353 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh in /usr/share/cloudstack-agent/lib/scripts/vm/hypervisor/patch.sh
2020-05-29 09:48:38,353 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh in /usr/share/cloudstack-agent/lib/scripts/vm/patch.sh
2020-05-29 09:48:38,353 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh in /usr/share/cloudstack-agent/lib/scripts/patch.sh
2020-05-29 09:48:38,353 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh in /usr/share/cloudstack-agent/lib/patch.sh
2020-05-29 09:48:38,353 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh in /usr/share/cloudstack-agent/patch.sh
2020-05-29 09:48:38,353 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh in /usr/share/patch.sh
2020-05-29 09:48:38,353 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh in /usr/patch.sh
2020-05-29 09:48:38,354 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh in /patch.sh
2020-05-29 09:48:38,354 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,354 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,354 DEBUG [utils.script.Script] (main:null) (logid:) Looking for patch.sh in /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/patch.sh
2020-05-29 09:48:38,354 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh in the classpath
2020-05-29 09:48:38,354 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,355 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,355 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh
2020-05-29 09:48:38,355 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,355 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh in /usr/share/cloudstack-agent/lib/scripts/vm/hypervisor/kvm/kvmheartbeat.sh
2020-05-29 09:48:38,355 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh in /usr/share/cloudstack-agent/lib/scripts/vm/hypervisor/kvmheartbeat.sh
2020-05-29 09:48:38,355 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh in /usr/share/cloudstack-agent/lib/scripts/vm/kvmheartbeat.sh
2020-05-29 09:48:38,355 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh in /usr/share/cloudstack-agent/lib/scripts/kvmheartbeat.sh
2020-05-29 09:48:38,355 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh in /usr/share/cloudstack-agent/lib/kvmheartbeat.sh
2020-05-29 09:48:38,356 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh in /usr/share/cloudstack-agent/kvmheartbeat.sh
2020-05-29 09:48:38,356 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh in /usr/share/kvmheartbeat.sh
2020-05-29 09:48:38,356 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh in /usr/kvmheartbeat.sh
2020-05-29 09:48:38,356 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh in /kvmheartbeat.sh
2020-05-29 09:48:38,356 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,356 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,357 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmheartbeat.sh in /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh
2020-05-29 09:48:38,357 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createvm.sh in the classpath
2020-05-29 09:48:38,357 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,357 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,357 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createvm.sh
2020-05-29 09:48:38,358 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,358 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createvm.sh in /usr/share/cloudstack-agent/lib/scripts/storage/qcow2/createvm.sh
2020-05-29 09:48:38,358 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createvm.sh in /usr/share/cloudstack-agent/lib/scripts/storage/createvm.sh
2020-05-29 09:48:38,358 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createvm.sh in /usr/share/cloudstack-agent/lib/scripts/createvm.sh
2020-05-29 09:48:38,358 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createvm.sh in /usr/share/cloudstack-agent/lib/createvm.sh
2020-05-29 09:48:38,359 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createvm.sh in /usr/share/cloudstack-agent/createvm.sh
2020-05-29 09:48:38,359 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createvm.sh in /usr/share/createvm.sh
2020-05-29 09:48:38,359 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createvm.sh in /usr/createvm.sh
2020-05-29 09:48:38,359 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createvm.sh in /createvm.sh
2020-05-29 09:48:38,359 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,360 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,360 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createvm.sh in /usr/share/cloudstack-common/scripts/storage/qcow2/createvm.sh
2020-05-29 09:48:38,360 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in the classpath
2020-05-29 09:48:38,360 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,360 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,360 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh
2020-05-29 09:48:38,361 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,361 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/scripts/storage/qcow2/managesnapshot.sh
2020-05-29 09:48:38,361 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/scripts/storage/managesnapshot.sh
2020-05-29 09:48:38,361 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/scripts/managesnapshot.sh
2020-05-29 09:48:38,361 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/managesnapshot.sh
2020-05-29 09:48:38,361 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/managesnapshot.sh
2020-05-29 09:48:38,361 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/managesnapshot.sh
2020-05-29 09:48:38,361 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/managesnapshot.sh
2020-05-29 09:48:38,361 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /managesnapshot.sh
2020-05-29 09:48:38,361 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,362 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,362 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-common/scripts/storage/qcow2/managesnapshot.sh
2020-05-29 09:48:38,362 DEBUG [utils.script.Script] (main:null) (logid:) Looking for resizevolume.sh in the classpath
2020-05-29 09:48:38,362 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,362 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,362 DEBUG [utils.script.Script] (main:null) (logid:) Looking for resizevolume.sh
2020-05-29 09:48:38,363 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,363 DEBUG [utils.script.Script] (main:null) (logid:) Looking for resizevolume.sh in /usr/share/cloudstack-agent/lib/scripts/storage/qcow2/resizevolume.sh
2020-05-29 09:48:38,363 DEBUG [utils.script.Script] (main:null) (logid:) Looking for resizevolume.sh in /usr/share/cloudstack-agent/lib/scripts/storage/resizevolume.sh
2020-05-29 09:48:38,363 DEBUG [utils.script.Script] (main:null) (logid:) Looking for resizevolume.sh in /usr/share/cloudstack-agent/lib/scripts/resizevolume.sh
2020-05-29 09:48:38,363 DEBUG [utils.script.Script] (main:null) (logid:) Looking for resizevolume.sh in /usr/share/cloudstack-agent/lib/resizevolume.sh
2020-05-29 09:48:38,363 DEBUG [utils.script.Script] (main:null) (logid:) Looking for resizevolume.sh in /usr/share/cloudstack-agent/resizevolume.sh
2020-05-29 09:48:38,363 DEBUG [utils.script.Script] (main:null) (logid:) Looking for resizevolume.sh in /usr/share/resizevolume.sh
2020-05-29 09:48:38,363 DEBUG [utils.script.Script] (main:null) (logid:) Looking for resizevolume.sh in /usr/resizevolume.sh
2020-05-29 09:48:38,363 DEBUG [utils.script.Script] (main:null) (logid:) Looking for resizevolume.sh in /resizevolume.sh
2020-05-29 09:48:38,363 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,364 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,364 DEBUG [utils.script.Script] (main:null) (logid:) Looking for resizevolume.sh in /usr/share/cloudstack-common/scripts/storage/qcow2/resizevolume.sh
2020-05-29 09:48:38,364 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh in the classpath
2020-05-29 09:48:38,364 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,364 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh in /usr/share/cloudstack-agent/lib/scripts/vm/hypervisor/kvm/kvmvmactivity.sh
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh in /usr/share/cloudstack-agent/lib/scripts/vm/hypervisor/kvmvmactivity.sh
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh in /usr/share/cloudstack-agent/lib/scripts/vm/kvmvmactivity.sh
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh in /usr/share/cloudstack-agent/lib/scripts/kvmvmactivity.sh
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh in /usr/share/cloudstack-agent/lib/kvmvmactivity.sh
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh in /usr/share/cloudstack-agent/kvmvmactivity.sh
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh in /usr/share/kvmvmactivity.sh
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh in /usr/kvmvmactivity.sh
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh in /kvmvmactivity.sh
2020-05-29 09:48:38,365 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,366 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,366 DEBUG [utils.script.Script] (main:null) (logid:) Looking for kvmvmactivity.sh in /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmvmactivity.sh
2020-05-29 09:48:38,366 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in the classpath
2020-05-29 09:48:38,366 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,367 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,367 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh
2020-05-29 09:48:38,367 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,367 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-agent/lib/scripts/storage/qcow2/createtmplt.sh
2020-05-29 09:48:38,367 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-agent/lib/scripts/storage/createtmplt.sh
2020-05-29 09:48:38,368 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-agent/lib/scripts/createtmplt.sh
2020-05-29 09:48:38,368 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-agent/lib/createtmplt.sh
2020-05-29 09:48:38,368 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-agent/createtmplt.sh
2020-05-29 09:48:38,368 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/createtmplt.sh
2020-05-29 09:48:38,368 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/createtmplt.sh
2020-05-29 09:48:38,368 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /createtmplt.sh
2020-05-29 09:48:38,368 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,369 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,369 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-common/scripts/storage/qcow2/createtmplt.sh
2020-05-29 09:48:38,369 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in the classpath
2020-05-29 09:48:38,369 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,370 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,370 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py
2020-05-29 09:48:38,370 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,370 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in /usr/share/cloudstack-agent/lib/scripts/vm/network/vnet/security_group.py
2020-05-29 09:48:38,370 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in /usr/share/cloudstack-agent/lib/scripts/vm/network/security_group.py
2020-05-29 09:48:38,370 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in /usr/share/cloudstack-agent/lib/scripts/vm/security_group.py
2020-05-29 09:48:38,370 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in /usr/share/cloudstack-agent/lib/scripts/security_group.py
2020-05-29 09:48:38,370 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in /usr/share/cloudstack-agent/lib/security_group.py
2020-05-29 09:48:38,371 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in /usr/share/cloudstack-agent/security_group.py
2020-05-29 09:48:38,371 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in /usr/share/security_group.py
2020-05-29 09:48:38,371 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in /usr/security_group.py
2020-05-29 09:48:38,371 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in /security_group.py
2020-05-29 09:48:38,371 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,371 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,371 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in /usr/share/cloudstack-common/scripts/vm/network/vnet/security_group.py
2020-05-29 09:48:38,372 DEBUG [utils.script.Script] (main:null) (logid:) Looking for security_group.py in /usr/share/cloudstack-common/scripts/vm/network/security_group.py
2020-05-29 09:48:38,372 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py in the classpath
2020-05-29 09:48:38,372 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,372 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,373 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py
2020-05-29 09:48:38,373 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,373 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py in /usr/share/cloudstack-agent/lib/scripts/vm/network/vnet/ovstunnel.py
2020-05-29 09:48:38,373 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py in /usr/share/cloudstack-agent/lib/scripts/vm/network/ovstunnel.py
2020-05-29 09:48:38,373 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py in /usr/share/cloudstack-agent/lib/scripts/vm/ovstunnel.py
2020-05-29 09:48:38,373 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py in /usr/share/cloudstack-agent/lib/scripts/ovstunnel.py
2020-05-29 09:48:38,373 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py in /usr/share/cloudstack-agent/lib/ovstunnel.py
2020-05-29 09:48:38,373 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py in /usr/share/cloudstack-agent/ovstunnel.py
2020-05-29 09:48:38,373 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py in /usr/share/ovstunnel.py
2020-05-29 09:48:38,373 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py in /usr/ovstunnel.py
2020-05-29 09:48:38,373 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py in /ovstunnel.py
2020-05-29 09:48:38,374 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,374 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,374 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovstunnel.py in /usr/share/cloudstack-common/scripts/vm/network/vnet/ovstunnel.py
2020-05-29 09:48:38,374 DEBUG [utils.script.Script] (main:null) (logid:) Looking for router_proxy.sh in the classpath
2020-05-29 09:48:38,375 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,375 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,375 DEBUG [utils.script.Script] (main:null) (logid:) Looking for router_proxy.sh
2020-05-29 09:48:38,375 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,375 DEBUG [utils.script.Script] (main:null) (logid:) Looking for router_proxy.sh in /usr/share/cloudstack-agent/lib/scripts/network/domr/router_proxy.sh
2020-05-29 09:48:38,375 DEBUG [utils.script.Script] (main:null) (logid:) Looking for router_proxy.sh in /usr/share/cloudstack-agent/lib/scripts/network/router_proxy.sh
2020-05-29 09:48:38,375 DEBUG [utils.script.Script] (main:null) (logid:) Looking for router_proxy.sh in /usr/share/cloudstack-agent/lib/scripts/router_proxy.sh
2020-05-29 09:48:38,375 DEBUG [utils.script.Script] (main:null) (logid:) Looking for router_proxy.sh in /usr/share/cloudstack-agent/lib/router_proxy.sh
2020-05-29 09:48:38,375 DEBUG [utils.script.Script] (main:null) (logid:) Looking for router_proxy.sh in /usr/share/cloudstack-agent/router_proxy.sh
2020-05-29 09:48:38,376 DEBUG [utils.script.Script] (main:null) (logid:) Looking for router_proxy.sh in /usr/share/router_proxy.sh
2020-05-29 09:48:38,376 DEBUG [utils.script.Script] (main:null) (logid:) Looking for router_proxy.sh in /usr/router_proxy.sh
2020-05-29 09:48:38,376 DEBUG [utils.script.Script] (main:null) (logid:) Looking for router_proxy.sh in /router_proxy.sh
2020-05-29 09:48:38,376 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,376 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,376 DEBUG [utils.script.Script] (main:null) (logid:) Looking for router_proxy.sh in /usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh
2020-05-29 09:48:38,377 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in the classpath
2020-05-29 09:48:38,377 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,377 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,377 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,377 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,378 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in /usr/share/cloudstack-agent/lib/scripts/vm/network/vnet/ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,378 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in /usr/share/cloudstack-agent/lib/scripts/vm/network/ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,378 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in /usr/share/cloudstack-agent/lib/scripts/vm/ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,378 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in /usr/share/cloudstack-agent/lib/scripts/ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,378 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in /usr/share/cloudstack-agent/lib/ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,378 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in /usr/share/cloudstack-agent/ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,378 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in /usr/share/ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,378 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in /usr/ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,378 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in /ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,378 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,379 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,379 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in /usr/share/cloudstack-common/scripts/vm/network/vnet/ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,379 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-dhcp-host.sh in /usr/share/cloudstack-common/scripts/vm/network/ovs-pvlan-dhcp-host.sh
2020-05-29 09:48:38,379 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in the classpath
2020-05-29 09:48:38,379 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,380 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,380 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh
2020-05-29 09:48:38,380 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,380 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in /usr/share/cloudstack-agent/lib/scripts/vm/network/vnet/ovs-pvlan-vm.sh
2020-05-29 09:48:38,380 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in /usr/share/cloudstack-agent/lib/scripts/vm/network/ovs-pvlan-vm.sh
2020-05-29 09:48:38,380 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in /usr/share/cloudstack-agent/lib/scripts/vm/ovs-pvlan-vm.sh
2020-05-29 09:48:38,380 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in /usr/share/cloudstack-agent/lib/scripts/ovs-pvlan-vm.sh
2020-05-29 09:48:38,380 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in /usr/share/cloudstack-agent/lib/ovs-pvlan-vm.sh
2020-05-29 09:48:38,380 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in /usr/share/cloudstack-agent/ovs-pvlan-vm.sh
2020-05-29 09:48:38,380 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in /usr/share/ovs-pvlan-vm.sh
2020-05-29 09:48:38,381 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in /usr/ovs-pvlan-vm.sh
2020-05-29 09:48:38,381 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in /ovs-pvlan-vm.sh
2020-05-29 09:48:38,381 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,381 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,381 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in /usr/share/cloudstack-common/scripts/vm/network/vnet/ovs-pvlan-vm.sh
2020-05-29 09:48:38,381 DEBUG [utils.script.Script] (main:null) (logid:) Looking for ovs-pvlan-vm.sh in /usr/share/cloudstack-common/scripts/vm/network/ovs-pvlan-vm.sh
2020-05-29 09:48:38,383 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in the classpath
2020-05-29 09:48:38,383 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,383 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,383 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh
2020-05-29 09:48:38,383 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /usr/share/cloudstack-agent/lib/scripts/vm/hypervisor/kvm/pingtest.sh
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /usr/share/cloudstack-agent/lib/scripts/vm/hypervisor/pingtest.sh
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /usr/share/cloudstack-agent/lib/scripts/vm/pingtest.sh
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /usr/share/cloudstack-agent/lib/scripts/pingtest.sh
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /usr/share/cloudstack-agent/lib/pingtest.sh
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /usr/share/cloudstack-agent/pingtest.sh
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /usr/share/pingtest.sh
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /usr/pingtest.sh
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /pingtest.sh
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/pingtest.sh
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /usr/share/cloudstack-common/scripts/vm/hypervisor/pingtest.sh
2020-05-29 09:48:38,384 DEBUG [utils.script.Script] (main:null) (logid:) Looking for pingtest.sh in /usr/share/cloudstack-common/scripts/vm/pingtest.sh
2020-05-29 09:48:38,385 DEBUG [kvm.resource.LibvirtConnection] (main:null) (logid:) Looking for libvirtd connection at: qemu:///system
2020-05-29 09:48:38,385 INFO [kvm.resource.LibvirtConnection] (main:null) (logid:) No existing libvirtd connection found. Opening a new one
2020-05-29 09:48:38,525 DEBUG [kvm.resource.LibvirtConnection] (main:null) (logid:) Successfully connected to libvirt at: qemu:///system
2020-05-29 09:48:38,529 DEBUG [kvm.resource.LibvirtComputingResource] (main:null) (logid:) Found libvirt default network, destroying it and setting autostart to false
2020-05-29 09:48:38,594 DEBUG [kvm.resource.LibvirtCapXMLParser] (main:null) (logid:) Found /usr/libexec/qemu-kvm as a suiteable emulator
2020-05-29 09:48:38,619 DEBUG [kvm.resource.LibvirtCapXMLParser] (main:null) (logid:) Found /usr/libexec/qemu-kvm as a suiteable emulator
2020-05-29 09:48:38,638 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in the classpath
2020-05-29 09:48:38,638 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,638 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,638 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh
2020-05-29 09:48:38,638 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,638 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/scripts/storage/qcow2/managesnapshot.sh
2020-05-29 09:48:38,638 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/scripts/storage/managesnapshot.sh
2020-05-29 09:48:38,638 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/scripts/managesnapshot.sh
2020-05-29 09:48:38,638 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/managesnapshot.sh
2020-05-29 09:48:38,638 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/managesnapshot.sh
2020-05-29 09:48:38,639 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/managesnapshot.sh
2020-05-29 09:48:38,639 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/managesnapshot.sh
2020-05-29 09:48:38,639 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /managesnapshot.sh
2020-05-29 09:48:38,639 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,639 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,639 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-common/scripts/storage/qcow2/managesnapshot.sh
2020-05-29 09:48:38,672 DEBUG [org.reflections.Reflections] (main:null) (logid:) going to scan these urls:
jar:file:/usr/share/cloudstack-agent/lib/cloud-plugin-hypervisor-kvm-4.13.0.0.jar!/
2020-05-29 09:48:38,734 INFO [org.reflections.Reflections] (main:null) (logid:) Reflections took 60 ms to scan 1 urls, producing 7 keys and 10 values
2020-05-29 09:48:38,757 DEBUG [kvm.storage.KVMStoragePoolManager] (main:null) (logid:) Registered a StorageAdaptor for libvirt
2020-05-29 09:48:38,758 DEBUG [kvm.storage.KVMStoragePoolManager] (main:null) (logid:) Registered a StorageAdaptor for Iscsi
2020-05-29 09:48:38,758 DEBUG [kvm.storage.KVMStoragePoolManager] (main:null) (logid:) Registered a StorageAdaptor for ManagedNFS
2020-05-29 09:48:38,758 INFO [kvm.resource.LibvirtComputingResource] (main:null) (logid:) No libvirt.vif.driver specified. Defaults to BridgeVifDriver.
2020-05-29 09:48:38,761 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/vnet2/bridge
2020-05-29 09:48:38,761 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/cloudbr249/bridge
2020-05-29 09:48:38,761 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge cloudbr249
2020-05-29 09:48:38,761 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond1.2278/bridge
2020-05-29 09:48:38,761 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/brbond1-2216/bridge
2020-05-29 09:48:38,761 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge brbond1-2216
2020-05-29 09:48:38,761 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond1.2022/bridge
2020-05-29 09:48:38,761 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/brbond1-2101/bridge
2020-05-29 09:48:38,761 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge brbond1-2101
2020-05-29 09:48:38,761 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond1.2483/bridge
2020-05-29 09:48:38,761 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/brbond1-2158/bridge
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge brbond1-2158
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/brbond1-2242/bridge
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge brbond1-2242
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond1.2596/bridge
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond3/bridge
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond1.2216/bridge
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond1/bridge
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/cloudbr2/bridge
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge cloudbr2
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond1.2101/bridge
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond1.2158/bridge
2020-05-29 09:48:38,762 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/brbond1-2011/bridge
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge brbond1-2011
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond1.2242/bridge
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/cloudbr0/bridge
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge cloudbr0
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/vnet3/bridge
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/vnet11/bridge
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/cloud0/bridge
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge cloud0
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/vnet1/bridge
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond1.2011/bridge
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/brbond1-2553/bridge
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge brbond1-2553
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/lo/bridge
2020-05-29 09:48:38,763 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond2/bridge
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond3.249/bridge
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/cloudbr3/bridge
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge cloudbr3
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/brbond1-2278/bridge
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge brbond1-2278
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/brbond1-2022/bridge
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge brbond1-2022
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond0/bridge
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/cloudbr1/bridge
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge cloudbr1
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/brbond1-2483/bridge
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge brbond1-2483
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/bond1.2553/bridge
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/brbond1-2596/bridge
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) Found bridge brbond1-2596
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking in file /sys/devices/virtual/net/vnet12/bridge
2020-05-29 09:48:38,764 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge cloudbr249
2020-05-29 09:48:38,765 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond3.249'
2020-05-29 09:48:38,766 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c grep ^Device\: /proc/net/vlan/bond3.249 | awk {'print $2'}
2020-05-29 09:48:38,768 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:38,772 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,772 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge brbond1-2216
2020-05-29 09:48:38,772 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'vnet12'
2020-05-29 09:48:38,773 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond1.2216'
2020-05-29 09:48:38,773 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c grep ^Device\: /proc/net/vlan/bond1.2216 | awk {'print $2'}
2020-05-29 09:48:38,774 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:38,778 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,778 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge brbond1-2101
2020-05-29 09:48:38,779 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond1.2101'
2020-05-29 09:48:38,779 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c grep ^Device\: /proc/net/vlan/bond1.2101 | awk {'print $2'}
2020-05-29 09:48:38,780 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:38,784 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,784 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge brbond1-2158
2020-05-29 09:48:38,784 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond1.2158'
2020-05-29 09:48:38,784 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c grep ^Device\: /proc/net/vlan/bond1.2158 | awk {'print $2'}
2020-05-29 09:48:38,785 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:38,789 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,789 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge brbond1-2242
2020-05-29 09:48:38,789 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'vnet2'
2020-05-29 09:48:38,790 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond1.2242'
2020-05-29 09:48:38,790 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c grep ^Device\: /proc/net/vlan/bond1.2242 | awk {'print $2'}
2020-05-29 09:48:38,791 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:38,794 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,795 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge cloudbr2
2020-05-29 09:48:38,795 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond2'
2020-05-29 09:48:38,795 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge brbond1-2011
2020-05-29 09:48:38,795 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond1.2011'
2020-05-29 09:48:38,795 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c grep ^Device\: /proc/net/vlan/bond1.2011 | awk {'print $2'}
2020-05-29 09:48:38,796 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:38,799 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,799 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge cloudbr0
2020-05-29 09:48:38,800 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond0'
2020-05-29 09:48:38,800 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge cloud0
2020-05-29 09:48:38,800 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) failing to get physical interface from bridge cloud0, did not find an eth*, bond*, team*, vlan*, em*, p*p*, ens*, eno*, enp*, or enx* in /sys/devices/virtual/net/cloud0/brif
2020-05-29 09:48:38,800 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge brbond1-2553
2020-05-29 09:48:38,800 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond1.2553'
2020-05-29 09:48:38,801 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c grep ^Device\: /proc/net/vlan/bond1.2553 | awk {'print $2'}
2020-05-29 09:48:38,802 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:38,805 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,805 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge cloudbr3
2020-05-29 09:48:38,805 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond3'
2020-05-29 09:48:38,805 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge brbond1-2278
2020-05-29 09:48:38,805 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond1.2278'
2020-05-29 09:48:38,806 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c grep ^Device\: /proc/net/vlan/bond1.2278 | awk {'print $2'}
2020-05-29 09:48:38,807 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:38,810 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,810 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge brbond1-2022
2020-05-29 09:48:38,810 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond1.2022'
2020-05-29 09:48:38,811 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c grep ^Device\: /proc/net/vlan/bond1.2022 | awk {'print $2'}
2020-05-29 09:48:38,812 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:38,815 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,816 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge cloudbr1
2020-05-29 09:48:38,816 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond1'
2020-05-29 09:48:38,816 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge brbond1-2483
2020-05-29 09:48:38,816 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond1.2483'
2020-05-29 09:48:38,817 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c grep ^Device\: /proc/net/vlan/bond1.2483 | awk {'print $2'}
2020-05-29 09:48:38,818 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:38,821 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,821 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) looking for pif for bridge brbond1-2596
2020-05-29 09:48:38,821 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) matchPifFileInDirectory: file name 'bond1.2596'
2020-05-29 09:48:38,822 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c grep ^Device\: /proc/net/vlan/bond1.2596 | awk {'print $2'}
2020-05-29 09:48:38,823 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:38,826 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:38,826 DEBUG [kvm.resource.BridgeVifDriver] (main:null) (logid:) done looking for pifs, no more bridges
2020-05-29 09:48:38,834 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in the classpath
2020-05-29 09:48:38,835 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,835 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,835 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh
2020-05-29 09:48:38,835 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,835 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/lib/scripts/vm/network/vnet/modifyvlan.sh
2020-05-29 09:48:38,835 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/lib/scripts/vm/network/modifyvlan.sh
2020-05-29 09:48:38,835 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/lib/scripts/vm/modifyvlan.sh
2020-05-29 09:48:38,836 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/lib/scripts/modifyvlan.sh
2020-05-29 09:48:38,836 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/lib/modifyvlan.sh
2020-05-29 09:48:38,836 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-agent/modifyvlan.sh
2020-05-29 09:48:38,836 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/modifyvlan.sh
2020-05-29 09:48:38,836 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/modifyvlan.sh
2020-05-29 09:48:38,836 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /modifyvlan.sh
2020-05-29 09:48:38,836 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,836 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,837 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvlan.sh in /usr/share/cloudstack-common/scripts/vm/network/vnet/modifyvlan.sh
2020-05-29 09:48:38,837 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh in the classpath
2020-05-29 09:48:38,837 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:38,837 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:38,837 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh
2020-05-29 09:48:38,837 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:38,838 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh in /usr/share/cloudstack-agent/lib/scripts/vm/network/vnet/modifyvxlan.sh
2020-05-29 09:48:38,838 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh in /usr/share/cloudstack-agent/lib/scripts/vm/network/modifyvxlan.sh
2020-05-29 09:48:38,838 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh in /usr/share/cloudstack-agent/lib/scripts/vm/modifyvxlan.sh
2020-05-29 09:48:38,838 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh in /usr/share/cloudstack-agent/lib/scripts/modifyvxlan.sh
2020-05-29 09:48:38,838 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh in /usr/share/cloudstack-agent/lib/modifyvxlan.sh
2020-05-29 09:48:38,838 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh in /usr/share/cloudstack-agent/modifyvxlan.sh
2020-05-29 09:48:38,838 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh in /usr/share/modifyvxlan.sh
2020-05-29 09:48:38,838 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh in /usr/modifyvxlan.sh
2020-05-29 09:48:38,838 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh in /modifyvxlan.sh
2020-05-29 09:48:38,838 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:38,839 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:38,839 DEBUG [utils.script.Script] (main:null) (logid:) Looking for modifyvxlan.sh in /usr/share/cloudstack-common/scripts/vm/network/vnet/modifyvxlan.sh
2020-05-29 09:48:38,839 DEBUG [kvm.resource.LibvirtComputingResource] (main:null) (logid:) Found pif: bond1 on cloudbr0, pif: bond2 on cloudbr2
2020-05-29 09:48:38,839 DEBUG [kvm.resource.LibvirtComputingResource] (main:null) (logid:) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py can_bridge_firewall --privnic bond2
2020-05-29 09:48:38,840 DEBUG [kvm.resource.LibvirtComputingResource] (main:null) (logid:) Executing while with timeout : 1800000
2020-05-29 09:48:39,041 DEBUG [kvm.resource.LibvirtComputingResource] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:39,042 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c ip route show default 0.0.0.0/0|head -1|awk '{print $3}'
2020-05-29 09:48:39,043 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:39,048 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:39,048 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c ethtool bond2 |grep Speed | cut -d \ -f 2
2020-05-29 09:48:39,050 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:39,054 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:39,054 DEBUG [kvm.resource.LibvirtComputingResource] (main:null) (logid:) device bond2 has speed: 2000
2020-05-29 09:48:39,055 DEBUG [utils.script.Script] (main:null) (logid:) Executing: /bin/bash -c ip route | grep 169.254.0.0/16
2020-05-29 09:48:39,056 DEBUG [utils.script.Script] (main:null) (logid:) Executing while with timeout : 1800000
2020-05-29 09:48:39,061 DEBUG [utils.script.Script] (main:null) (logid:) Execution is successful.
2020-05-29 09:48:39,082 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in the classpath
2020-05-29 09:48:39,083 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:39,083 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:39,083 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh
2020-05-29 09:48:39,083 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:39,083 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-agent/lib/scripts/storage/qcow2/createtmplt.sh
2020-05-29 09:48:39,084 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-agent/lib/scripts/storage/createtmplt.sh
2020-05-29 09:48:39,084 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-agent/lib/scripts/createtmplt.sh
2020-05-29 09:48:39,084 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-agent/lib/createtmplt.sh
2020-05-29 09:48:39,084 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-agent/createtmplt.sh
2020-05-29 09:48:39,084 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/createtmplt.sh
2020-05-29 09:48:39,084 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/createtmplt.sh
2020-05-29 09:48:39,084 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /createtmplt.sh
2020-05-29 09:48:39,084 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:39,084 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:39,084 DEBUG [utils.script.Script] (main:null) (logid:) Looking for createtmplt.sh in /usr/share/cloudstack-common/scripts/storage/qcow2/createtmplt.sh
2020-05-29 09:48:39,084 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in the classpath
2020-05-29 09:48:39,085 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:39,085 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:39,085 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh
2020-05-29 09:48:39,085 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:39,085 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/scripts/storage/qcow2/managesnapshot.sh
2020-05-29 09:48:39,085 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/scripts/storage/managesnapshot.sh
2020-05-29 09:48:39,085 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/scripts/managesnapshot.sh
2020-05-29 09:48:39,085 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/lib/managesnapshot.sh
2020-05-29 09:48:39,085 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-agent/managesnapshot.sh
2020-05-29 09:48:39,085 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/managesnapshot.sh
2020-05-29 09:48:39,086 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/managesnapshot.sh
2020-05-29 09:48:39,086 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /managesnapshot.sh
2020-05-29 09:48:39,086 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:39,086 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:39,086 DEBUG [utils.script.Script] (main:null) (logid:) Looking for managesnapshot.sh in /usr/share/cloudstack-common/scripts/storage/qcow2/managesnapshot.sh
2020-05-29 09:48:39,103 DEBUG [cloud.agent.Agent] (main:null) (logid:) Adding shutdown hook
2020-05-29 09:48:39,103 INFO [cloud.agent.Agent] (main:null) (logid:) Agent [id = 0 : type = LibvirtComputingResource : zone = 2 : pod = 2 : workers = 5 : host = 10.222.0.200 : port = 8251
2020-05-29 09:48:39,103 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-setup in the classpath
2020-05-29 09:48:39,104 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:39,104 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:39,104 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-setup
2020-05-29 09:48:39,104 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:39,104 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-setup in /usr/share/cloudstack-agent/lib/scripts/util/keystore-setup
2020-05-29 09:48:39,104 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-setup in /usr/share/cloudstack-agent/lib/scripts/keystore-setup
2020-05-29 09:48:39,104 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-setup in /usr/share/cloudstack-agent/lib/keystore-setup
2020-05-29 09:48:39,104 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-setup in /usr/share/cloudstack-agent/keystore-setup
2020-05-29 09:48:39,104 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-setup in /usr/share/keystore-setup
2020-05-29 09:48:39,104 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-setup in /usr/keystore-setup
2020-05-29 09:48:39,105 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-setup in /keystore-setup
2020-05-29 09:48:39,105 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:39,105 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:39,105 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-setup in /usr/share/cloudstack-common/scripts/util/keystore-setup
2020-05-29 09:48:39,105 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-cert-import in the classpath
2020-05-29 09:48:39,105 DEBUG [utils.script.Script] (main:null) (logid:) System resource: null
2020-05-29 09:48:39,106 DEBUG [utils.script.Script] (main:null) (logid:) Classpath resource: null
2020-05-29 09:48:39,106 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-cert-import
2020-05-29 09:48:39,106 DEBUG [utils.script.Script] (main:null) (logid:) Current binaries reside at /usr/share/cloudstack-agent/lib
2020-05-29 09:48:39,106 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-cert-import in /usr/share/cloudstack-agent/lib/scripts/util/keystore-cert-import
2020-05-29 09:48:39,106 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-cert-import in /usr/share/cloudstack-agent/lib/scripts/keystore-cert-import
2020-05-29 09:48:39,106 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-cert-import in /usr/share/cloudstack-agent/lib/keystore-cert-import
2020-05-29 09:48:39,106 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-cert-import in /usr/share/cloudstack-agent/keystore-cert-import
2020-05-29 09:48:39,106 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-cert-import in /usr/share/keystore-cert-import
2020-05-29 09:48:39,106 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-cert-import in /usr/keystore-cert-import
2020-05-29 09:48:39,106 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-cert-import in /keystore-cert-import
2020-05-29 09:48:39,106 DEBUG [utils.script.Script] (main:null) (logid:) Searching in environment.properties
2020-05-29 09:48:39,107 DEBUG [utils.script.Script] (main:null) (logid:) environment.properties says scripts should be in /usr/share/cloudstack-common
2020-05-29 09:48:39,107 DEBUG [utils.script.Script] (main:null) (logid:) Looking for keystore-cert-import in /usr/share/cloudstack-common/scripts/util/keystore-cert-import
2020-05-29 09:48:39,113 INFO [utils.nio.NioClient] (main:null) (logid:) Connecting to 10.222.0.200:8251
2020-05-29 09:48:39,118 INFO [utils.nio.Link] (main:null) (logid:) Conf file found: /etc/cloudstack/agent/agent.properties
2020-05-29 09:48:39,508 INFO [utils.nio.NioClient] (main:null) (logid:) SSL: Handshake done
2020-05-29 09:48:39,508 INFO [utils.nio.NioClient] (main:null) (logid:) Connected to 10.222.0.200:8251
2020-05-29 09:48:39,512 DEBUG [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
2020-05-29 09:48:39,563 DEBUG [kvm.resource.LibvirtCapXMLParser] (Agent-Handler-1:null) (logid:) Found /usr/libexec/qemu-kvm as a suiteable emulator
2020-05-29 09:48:39,573 DEBUG [cloud.resource.ServerResourceBase] (Agent-Handler-1:null) (logid:) Parameters for private nic: 10.222.5.10 - 90:e2:ba:35:34:a0-255.255.252.0
2020-05-29 09:48:39,573 DEBUG [cloud.resource.ServerResourceBase] (Agent-Handler-1:null) (logid:) Storage has its now nic: cloudbr249
2020-05-29 09:48:39,574 DEBUG [cloud.resource.ServerResourceBase] (Agent-Handler-1:null) (logid:) Parameters for storage nic: 10.223.5.10 - a0:36:9f:20:28:5c-255.255.0.0
2020-05-29 09:48:39,574 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/versions.sh
2020-05-29 09:48:39,575 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Executing while with timeout : 1800000
2020-05-29 09:48:39,592 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Execution is successful.
2020-05-29 09:48:39,627 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Executing: sudo grep InitiatorName= /etc/iscsi/initiatorname.iscsi
2020-05-29 09:48:39,628 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:48:39,675 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Execution is successful.
2020-05-29 09:48:39,675 INFO [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) (logid:) Attempting to create storage pool 6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad (Filesystem) in libvirt
2020-05-29 09:48:39,675 DEBUG [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
2020-05-29 09:48:39,683 ERROR [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) (logid:) Connection with libvirtd is broken: invalid connection pointer in virConnectGetVersion
2020-05-29 09:48:39,683 DEBUG [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) (logid:) Opening a new libvirtd connection to: qemu:///system
2020-05-29 09:48:39,701 INFO [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) (logid:) Found existing defined storage pool 6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad, using it.
2020-05-29 09:48:39,704 INFO [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) (logid:) Trying to fetch storage pool 6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad from libvirt
2020-05-29 09:48:39,704 DEBUG [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
2020-05-29 09:48:39,741 DEBUG [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) (logid:) Succesfully refreshed pool 6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad Capacity: 80491315200 Used: 5097652224 Available: 75393662976
2020-05-29 09:48:39,745 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Executing: hostname
2020-05-29 09:48:39,746 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Executing while with timeout : 500
2020-05-29 09:48:39,747 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Execution is successful.
2020-05-29 09:48:39,748 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Executing: hostname
2020-05-29 09:48:39,749 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Executing while with timeout : 500
2020-05-29 09:48:39,750 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Execution is successful.
2020-05-29 09:48:39,800 INFO [cloud.serializer.GsonHelper] (Agent-Handler-1:null) (logid:) Default Builder inited.
2020-05-29 09:48:39,825 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Sending Startup: Seq 0-0: { Cmd , MgmtId: -1, via: 0, Ver: v1, Flags: 1, [{"com.cloud.agent.api.StartupRoutingCommand":{"cpuSockets":2,"cpus":16,"speed":2395,"memory":66469244928,"dom0MinMemory":1073741824,"poolSync":false,"supportsClonedVolumes":false,"caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"Host.OS.Kernel.Version":"4.17.13-1.el7.elrepo.x86_64","com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS.Version":"7.8.2003","secured":"true","Host.OS":"CentOS"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"2","pod":"2","cluster":"18","guid":"862603de-4865-3241-8055-e5bde9e25f6b-LibvirtComputingResource","name":"kvm0201","id":0,"version":"4.13.0.0","iqn":"iqn.1994-05.com.redhat:b487e3cd1fa2","privateIpAddress":"10.222.5.10","privateMacAddress":"90:e2:ba:35:34:a0","privateNetmask":"255.255.252.0","storageIpAddress":"10.223.5.10","storageNetmask":"255.255.0.0","storageMacAddress":"a0:36:9f:20:28:5c","resourceName":"LibvirtComputingResource","gatewayIpAddress":"10.222.4.1","msHostList":"10.222.0.200@static","wait":0}},{"com.cloud.agent.api.StartupStorageCommand":{"totalSize":0,"poolInfo":{"uuid":"6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad","host":"10.222.5.10","localPath":"/var/lib/libvirt/images","hostPath":"/var/lib/libvirt/images","poolType":"Filesystem","capacityBytes":80491315200,"availableBytes":75393662976},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"2","pod":"2","guid":"862603de-4865-3241-8055-e5bde9e25f6b-LibvirtComputingResource","name":"kvm0201","id":0,"version":"4.13.0.0","resourceName":"LibvirtComputingResource","msHostList":"10.222.0.200@static","wait":0}}] }
2020-05-29 09:48:39,825 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Startup task created
2020-05-29 09:48:40,110 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Received response: Seq 0-0: { Ans: , MgmtId: 249302044940158, via: -1, Ver: v1, Flags: 100000, [{"com.cloud.agent.api.StartupAnswer":{"hostId":0,"pingInterval":60,"result":true,"wait":0}}] }
2020-05-29 09:48:40,111 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Startup task cancelled
2020-05-29 09:48:40,111 INFO [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Proccess agent startup answer, agent id = 0
2020-05-29 09:48:40,111 INFO [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Set agent id 0
2020-05-29 09:48:40,117 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Adding a watch list
2020-05-29 09:48:40,118 INFO [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Startup Response Received: agent id = 0
2020-05-29 09:48:40,119 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-1:null) (logid:) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms
2020-05-29 09:48:40,121 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-1:null) (logid:) Executing while with timeout : 1800000
2020-05-29 09:48:40,333 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:03755f2c) Request:Seq 98-4044513940355416065: { Cmd , MgmtId: 249302044940158, via: 98, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CleanupNetworkRulesCmd":{"interval":1995,"wait":0}}] }
2020-05-29 09:48:40,334 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:03755f2c) Processing command: com.cloud.agent.api.CleanupNetworkRulesCmd
2020-05-29 09:48:40,334 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:03755f2c) Adding a watch list
2020-05-29 09:48:40,335 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:03755f2c) Seq 98-4044513940355416065: { Ans: , MgmtId: 249302044940158, via: 98, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
2020-05-29 09:48:40,337 DEBUG [org.reflections.Reflections] (Agent-Handler-4:null) (logid:03755f2c) going to scan these urls:
jar:file:/usr/share/cloudstack-agent/lib/cloud-plugin-hypervisor-kvm-4.13.0.0.jar!/
2020-05-29 09:48:40,345 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:03755f2c) Request:Seq 98-4044513940355416066: { Cmd , MgmtId: 249302044940158, via: 98, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":true,"pool":{"id":20,"uuid":"2258aa76-7813-354d-b274-961fb337e716","host":"ceph-mon","path":"rbd","userInfo":"admin:AQDWA1pbHMIfCBAAlO-Sl5U5QGHM_+nH3u7K7A==","port":6789,"type":"RBD"},"localPath":"/mnt//9e8299eb-132c-3dc7-931e-a1591aacdf1a","wait":0}}] }
2020-05-29 09:48:40,345 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:03755f2c) Processing command: com.cloud.agent.api.ModifyStoragePoolCommand
2020-05-29 09:48:40,366 INFO [org.reflections.Reflections] (Agent-Handler-4:null) (logid:03755f2c) Reflections took 28 ms to scan 1 urls, producing 5 keys and 153 values
2020-05-29 09:48:40,368 DEBUG [org.reflections.Reflections] (Agent-Handler-4:null) (logid:03755f2c) expanded subtype java.lang.Comparable -> java.lang.Enum
2020-05-29 09:48:40,368 DEBUG [org.reflections.Reflections] (Agent-Handler-4:null) (logid:03755f2c) expanded subtype java.io.Serializable -> java.lang.Enum
2020-05-29 09:48:40,375 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-1:null) (logid:) Execution is successful.
2020-05-29 09:48:40,376 DEBUG [kvm.resource.LibvirtConnection] (UgentTask-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
2020-05-29 09:48:40,417 DEBUG [cloud.agent.Agent] (UgentTask-1:null) (logid:) Sending ping: Seq 0-1: { Cmd , MgmtId: -1, via: 0, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"_hostVmStateReport":{"i-169-1740-VM":{"state":"PowerOn","host":"kvm0201"},"i-145-1541-VM":{"state":"PowerOn","host":"kvm0201"},"i-145-1529-VM":{"state":"PowerOn","host":"kvm0201"},"i-151-1641-VM":{"state":"PowerOn","host":"kvm0201"},"i-129-1522-VM":{"state":"PowerOn","host":"kvm0201"}},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":0,"wait":0}}] }
2020-05-29 09:48:40,463 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-4:null) (logid:03755f2c) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py cleanup_rules
2020-05-29 09:48:40,463 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:03755f2c) Attempting to create storage pool 2258aa76-7813-354d-b274-961fb337e716 (RBD) in libvirt
2020-05-29 09:48:40,463 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:03755f2c) Looking for libvirtd connection at: qemu:///system
2020-05-29 09:48:40,464 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-4:null) (logid:03755f2c) Executing while with timeout : 1800000
2020-05-29 09:48:40,469 WARN [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:03755f2c) Storage pool 2258aa76-7813-354d-b274-961fb337e716 was not found running in libvirt. Need to create it.
2020-05-29 09:48:40,469 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:03755f2c) Didn't find an existing storage pool 2258aa76-7813-354d-b274-961fb337e716 by UUID, checking for pools with duplicate paths
2020-05-29 09:48:40,474 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:03755f2c) Checking path of existing pool 6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad against pool we want to create
2020-05-29 09:48:40,482 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:03755f2c) Checking path of existing pool 31bf418a-be32-3a18-8c5d-c62eb4358eda against pool we want to create
2020-05-29 09:48:40,489 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:03755f2c) Checking path of existing pool b9a8ad4a-9032-3db2-ba98-938b891e1af1 against pool we want to create
2020-05-29 09:48:40,492 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Received response: Seq 0-1: { Ans: , MgmtId: 249302044940158, via: 98, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":0,"wait":0},"result":true,"wait":0}}] }
2020-05-29 09:48:40,495 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:03755f2c) Attempting to create storage pool 2258aa76-7813-354d-b274-961fb337e716
2020-05-29 09:48:40,496 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:03755f2c) <secret ephemeral='no' private='no'>
<uuid>2258aa76-7813-354d-b274-961fb337e716</uuid>
<usage type='ceph'>
<name>admin@ceph-mon:6789/rbd</name>
</usage>
</secret>
2020-05-29 09:48:40,542 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:03755f2c) <pool type='rbd'>
<name>2258aa76-7813-354d-b274-961fb337e716</name>
<uuid>2258aa76-7813-354d-b274-961fb337e716</uuid>
<source>
<host name='ceph-mon' port='6789'/>
<name>rbd</name>
<auth username='admin' type='ceph'>
<secret uuid='2258aa76-7813-354d-b274-961fb337e716'/>
</auth>
</source>
</pool>
2020-05-29 09:48:40,665 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-4:null) (logid:03755f2c) Execution is successful.
2020-05-29 09:48:40,666 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null) (logid:03755f2c) Watch Sent: Seq 98-4044513940355416065: { Ans: , MgmtId: 249302044940158, via: 98, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"details":"","wait":0}}] }
2020-05-29 09:49:26,202 ERROR [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:03755f2c) Failed to create RBD storage pool: org.libvirt.LibvirtException: failed to open the RBD image 'c47d7221-a664-41c6-a791-1148ec6f0850': No such file or directory
2020-05-29 09:49:26,202 ERROR [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:03755f2c) Failed to create the RBD storage pool, cleaning up the libvirt secret
2020-05-29 09:49:26,207 WARN [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:03755f2c) Caught:
com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool: 2258aa76-7813-354d-b274-961fb337e716
at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:585)
at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.createStoragePool(KVMStoragePoolManager.java:329)
at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.createStoragePool(KVMStoragePoolManager.java:323)
at com.cloud.hypervisor.kvm.resource.wrapper.LibvirtModifyStoragePoolCommandWrapper.execute(LibvirtModifyStoragePoolCommandWrapper.java:42)
at com.cloud.hypervisor.kvm.resource.wrapper.LibvirtModifyStoragePoolCommandWrapper.execute(LibvirtModifyStoragePoolCommandWrapper.java:35)
at com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1476)
at com.cloud.agent.Agent.processRequest(Agent.java:640)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1053)
at com.cloud.utils.nio.Task.call(Task.java:83)
at com.cloud.utils.nio.Task.call(Task.java:29)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2020-05-29 09:49:26,211 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:03755f2c) Seq 98-4044513940355416066: { Ans: , MgmtId: 249302044940158, via: 98, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool: 2258aa76-7813-354d-b274-961fb337e716\n\tat com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:585)\n\tat com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.createStoragePool(KVMStoragePoolManager.java:329)\n\tat com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.createStoragePool(KVMStoragePoolManager.java:323)\n\tat com.cloud.hypervisor.kvm.resource.wrapper.LibvirtModifyStoragePoolCommandWrapper.execute(LibvirtModifyStoragePoolCommandWrapper.java:42)\n\tat com.cloud.hypervisor.kvm.resource.wrapper.LibvirtModifyStoragePoolCommandWrapper.execute(LibvirtModifyStoragePoolCommandWrapper.java:35)\n\tat com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1476)\n\tat com.cloud.agent.Agent.processRequest(Agent.java:640)\n\tat com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1053)\n\tat com.cloud.utils.nio.Task.call(Task.java:83)\n\tat com.cloud.utils.nio.Task.call(Task.java:29)\n\tat java.util.concurrent.FutureTask.run(FutureTask.java:266)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n\tat java.lang.Thread.run(Thread.java:748)\n","wait":0}}] }
2020-05-29 09:49:26,279 DEBUG [utils.nio.NioConnection] (Agent-NioConnectionHandler-1:null) (logid:) Location 1: Socket Socket[addr=/10.222.0.200,port=8251,localport=33962] closed on read. Probably -1 returned: Connection closed with -1 on reading size.
2020-05-29 09:49:26,279 DEBUG [utils.nio.NioConnection] (Agent-NioConnectionHandler-1:null) (logid:) Closing socket Socket[addr=/10.222.0.200,port=8251,localport=33962]
2020-05-29 09:49:26,280 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Clearing watch list: 2
2020-05-29 09:49:26,281 INFO [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Lost connection to host: 10.222.0.200. Attempting reconnection while we still have 0 commands in progress.
2020-05-29 09:49:26,281 INFO [utils.nio.NioClient] (Agent-Handler-2:null) (logid:) NioClient connection closed
2020-05-29 09:49:26,281 INFO [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Reconnecting to host:10.222.0.200
2020-05-29 09:49:26,282 INFO [utils.nio.NioClient] (Agent-Handler-2:null) (logid:) Connecting to 10.222.0.200:8251
2020-05-29 09:49:26,283 INFO [utils.nio.Link] (Agent-Handler-2:null) (logid:) Conf file found: /etc/cloudstack/agent/agent.properties
2020-05-29 09:49:26,375 INFO [utils.nio.NioClient] (Agent-Handler-2:null) (logid:) SSL: Handshake done
2020-05-29 09:49:26,375 INFO [utils.nio.NioClient] (Agent-Handler-2:null) (logid:) Connected to 10.222.0.200:8251
2020-05-29 09:49:26,376 DEBUG [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
2020-05-29 09:49:26,428 DEBUG [kvm.resource.LibvirtCapXMLParser] (Agent-Handler-1:null) (logid:) Found /usr/libexec/qemu-kvm as a suiteable emulator
2020-05-29 09:49:26,433 DEBUG [cloud.resource.ServerResourceBase] (Agent-Handler-1:null) (logid:) Parameters for private nic: 10.222.5.10 - 90:e2:ba:35:34:a0-255.255.252.0
2020-05-29 09:49:26,433 DEBUG [cloud.resource.ServerResourceBase] (Agent-Handler-1:null) (logid:) Storage has its now nic: cloudbr249
2020-05-29 09:49:26,433 DEBUG [cloud.resource.ServerResourceBase] (Agent-Handler-1:null) (logid:) Parameters for storage nic: 10.223.5.10 - a0:36:9f:20:28:5c-255.255.0.0
2020-05-29 09:49:26,433 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/versions.sh
2020-05-29 09:49:26,435 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Executing while with timeout : 1800000
2020-05-29 09:49:26,449 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Execution is successful.
2020-05-29 09:49:26,484 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Executing: sudo grep InitiatorName= /etc/iscsi/initiatorname.iscsi
2020-05-29 09:49:26,486 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Executing while with timeout : 3600000
2020-05-29 09:49:26,532 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) (logid:) Execution is successful.
2020-05-29 09:49:26,534 INFO [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) (logid:) Attempting to create storage pool 6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad (Filesystem) in libvirt
2020-05-29 09:49:26,534 DEBUG [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
2020-05-29 09:49:26,535 ERROR [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) (logid:) Connection with libvirtd is broken: invalid connection pointer in virConnectGetVersion
2020-05-29 09:49:26,535 DEBUG [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) (logid:) Opening a new libvirtd connection to: qemu:///system
2020-05-29 09:49:26,553 INFO [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) (logid:) Found existing defined storage pool 6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad, using it.
2020-05-29 09:49:26,556 INFO [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) (logid:) Trying to fetch storage pool 6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad from libvirt
2020-05-29 09:49:26,556 DEBUG [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
2020-05-29 09:49:26,583 DEBUG [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) (logid:) Succesfully refreshed pool 6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad Capacity: 80491315200 Used: 5097652224 Available: 75393662976
2020-05-29 09:49:26,583 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Executing: hostname
2020-05-29 09:49:26,584 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Executing while with timeout : 500
2020-05-29 09:49:26,585 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Execution is successful.
2020-05-29 09:49:26,587 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Executing: hostname
2020-05-29 09:49:26,588 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Executing while with timeout : 500
2020-05-29 09:49:26,589 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Execution is successful.
2020-05-29 09:49:26,593 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Sending Startup: Seq 0-2: { Cmd , MgmtId: -1, via: 0, Ver: v1, Flags: 1, [{"com.cloud.agent.api.StartupRoutingCommand":{"cpuSockets":2,"cpus":16,"speed":2395,"memory":66469244928,"dom0MinMemory":1073741824,"poolSync":false,"supportsClonedVolumes":false,"caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"Host.OS.Kernel.Version":"4.17.13-1.el7.elrepo.x86_64","com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS.Version":"7.8.2003","secured":"true","Host.OS":"CentOS"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"2","pod":"2","cluster":"18","guid":"862603de-4865-3241-8055-e5bde9e25f6b-LibvirtComputingResource","name":"kvm0201","id":0,"version":"4.13.0.0","iqn":"iqn.1994-05.com.redhat:b487e3cd1fa2","privateIpAddress":"10.222.5.10","privateMacAddress":"90:e2:ba:35:34:a0","privateNetmask":"255.255.252.0","storageIpAddress":"10.223.5.10","storageNetmask":"255.255.0.0","storageMacAddress":"a0:36:9f:20:28:5c","resourceName":"LibvirtComputingResource","gatewayIpAddress":"10.222.4.1","msHostList":"10.222.0.200@static","wait":0}},{"com.cloud.agent.api.StartupStorageCommand":{"totalSize":0,"poolInfo":{"uuid":"6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad","host":"10.222.5.10","localPath":"/var/lib/libvirt/images","hostPath":"/var/lib/libvirt/images","poolType":"Filesystem","capacityBytes":80491315200,"availableBytes":75393662976},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"2","pod":"2","guid":"862603de-4865-3241-8055-e5bde9e25f6b-LibvirtComputingResource","name":"kvm0201","id":0,"version":"4.13.0.0","resourceName":"LibvirtComputingResource","msHostList":"10.222.0.200@static","wait":0}}] }
2020-05-29 09:49:26,594 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) (logid:) Startup task created
2020-05-29 09:49:30,432 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Received response: Seq 0-2: { Ans: , MgmtId: 249302044940158, via: -1, Ver: v1, Flags: 100000, [{"com.cloud.agent.api.StartupAnswer":{"hostId":0,"pingInterval":60,"result":true,"wait":0}}] }
2020-05-29 09:49:30,433 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Startup task cancelled
2020-05-29 09:49:30,434 INFO [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Proccess agent startup answer, agent id = 0
2020-05-29 09:49:30,434 INFO [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Set agent id 0
2020-05-29 09:49:30,435 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Adding a watch list
2020-05-29 09:49:30,435 INFO [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Startup Response Received: agent id = 0
2020-05-29 09:49:30,436 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-2:null) (logid:) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms
2020-05-29 09:49:30,438 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-2:null) (logid:) Executing while with timeout : 1800000
2020-05-29 09:49:30,551 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:f9ab491a) Request:Seq 98-3748683739832516609: { Cmd , MgmtId: 249302044940158, via: 98, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CleanupNetworkRulesCmd":{"interval":2600,"wait":0}}] }
2020-05-29 09:49:30,552 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:f9ab491a) Processing command: com.cloud.agent.api.CleanupNetworkRulesCmd
2020-05-29 09:49:30,552 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:f9ab491a) Adding a watch list
2020-05-29 09:49:30,553 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:f9ab491a) Seq 98-3748683739832516609: { Ans: , MgmtId: 249302044940158, via: 98, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
2020-05-29 09:49:30,553 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-4:null) (logid:f9ab491a) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py cleanup_rules
2020-05-29 09:49:30,555 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-4:null) (logid:f9ab491a) Executing while with timeout : 1800000
2020-05-29 09:49:30,602 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:f9ab491a) Request:Seq 98-3748683739832516610: { Cmd , MgmtId: 249302044940158, via: 98, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":true,"pool":{"id":20,"uuid":"2258aa76-7813-354d-b274-961fb337e716","host":"ceph-mon","path":"rbd","userInfo":"admin:AQDWA1pbHMIfCBAAlO-Sl5U5QGHM_+nH3u7K7A==","port":6789,"type":"RBD"},"localPath":"/mnt//9e8299eb-132c-3dc7-931e-a1591aacdf1a","wait":0}}] }
2020-05-29 09:49:30,602 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:f9ab491a) Processing command: com.cloud.agent.api.ModifyStoragePoolCommand
2020-05-29 09:49:30,602 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:f9ab491a) Attempting to create storage pool 2258aa76-7813-354d-b274-961fb337e716 (RBD) in libvirt
2020-05-29 09:49:30,602 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:f9ab491a) Looking for libvirtd connection at: qemu:///system
2020-05-29 09:49:30,620 WARN [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:f9ab491a) Storage pool 2258aa76-7813-354d-b274-961fb337e716 was not found running in libvirt. Need to create it.
2020-05-29 09:49:30,620 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:f9ab491a) Didn't find an existing storage pool 2258aa76-7813-354d-b274-961fb337e716 by UUID, checking for pools with duplicate paths
2020-05-29 09:49:30,626 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:f9ab491a) Checking path of existing pool 6fba7a90-a3e4-460b-9c21-b1c66ebbd1ad against pool we want to create
2020-05-29 09:49:30,634 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:f9ab491a) Checking path of existing pool 31bf418a-be32-3a18-8c5d-c62eb4358eda against pool we want to create
2020-05-29 09:49:30,640 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:f9ab491a) Checking path of existing pool b9a8ad4a-9032-3db2-ba98-938b891e1af1 against pool we want to create
2020-05-29 09:49:30,648 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:f9ab491a) Attempting to create storage pool 2258aa76-7813-354d-b274-961fb337e716
2020-05-29 09:49:30,648 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:f9ab491a) <secret ephemeral='no' private='no'>
<uuid>2258aa76-7813-354d-b274-961fb337e716</uuid>
<usage type='ceph'>
<name>admin@ceph-mon:6789/rbd</name>
</usage>
</secret>
2020-05-29 09:49:30,688 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:f9ab491a) <pool type='rbd'>
<name>2258aa76-7813-354d-b274-961fb337e716</name>
<uuid>2258aa76-7813-354d-b274-961fb337e716</uuid>
<source>
<host name='ceph-mon' port='6789'/>
<name>rbd</name>
<auth username='admin' type='ceph'>
<secret uuid='2258aa76-7813-354d-b274-961fb337e716'/>
</auth>
</source>
</pool>
~~~
Libvirtd Log :
~~~
https://gist.github.com/ccycv/1cd74f3ea432ed17ee1e260051380107
~~~
##### STEPS TO REPRODUCE
~~~
Deploy new VM
~~~
<!-- You can also paste gist.github.com links for larger files -->
##### EXPECTED RESULTS
~~~
No Issue
~~~
##### ACTUAL RESULTS
~~~
Issue is persisting
~~~
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [cloudstack] ccycv closed issue #4118: com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool - Ceph Storage - ACS 4.13
Posted by GitBox <gi...@apache.org>.
ccycv closed issue #4118:
URL: https://github.com/apache/cloudstack/issues/4118
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [cloudstack] ccycv commented on issue #4118: com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool - Ceph Storage - ACS 4.13
Posted by GitBox <gi...@apache.org>.
ccycv commented on issue #4118:
URL: https://github.com/apache/cloudstack/issues/4118#issuecomment-636076816
There was a VM in database in Expunging state, which for some reasons was not Destroy state.
- I changed the state in db for it to - Destroy
- I changed the POOL_ID to "NULL" for this volume with his related to the above VM : c47d7221-a664-41c6-a791-1148ec6f0850
- I have removed this volume "c47d7221-a664-41c6-a791-1148ec6f0850" from ceph storage.
After this everything was back to normal.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [cloudstack] ccycv commented on issue #4118: com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool - Ceph Storage - ACS 4.13
Posted by GitBox <gi...@apache.org>.
ccycv commented on issue #4118:
URL: https://github.com/apache/cloudstack/issues/4118#issuecomment-636077621
I think this should not happen.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [cloudstack] ccycv commented on issue #4118: com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool - Ceph Storage - ACS 4.13
Posted by GitBox <gi...@apache.org>.
ccycv commented on issue #4118:
URL: https://github.com/apache/cloudstack/issues/4118#issuecomment-648601852
Hello,
We fixed this, it was related to a stuck image, we have removed from db and from storage. Please see all the details : https://github.com/apache/cloudstack/issues/4118
Thank you!
Regards,
Cristian
From: Rohit Yadav <no...@github.com>
Sent: Wednesday, June 24, 2020 6:11 AM
To: apache/cloudstack <cl...@noreply.github.com>
Cc: ccycv <cr...@istream.today>; Mention <me...@noreply.github.com>
Subject: Re: [apache/cloudstack] com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool - Ceph Storage - ACS 4.13 (#4118)
@ccycv <https://github.com/ccycv> can you try on 4.13.1.0 or 4.14.1.0? Are the ceph credentials correct, or was the storage pool not created on Ceph; or removed out-of-band in ceph-mgr?
—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub <https://github.com/apache/cloudstack/issues/4118#issuecomment-648555914> , or unsubscribe <https://github.com/notifications/unsubscribe-auth/AFR53GMOZRIBKLGOROW42JLRYFVD7ANCNFSM4NN24OIA> . <https://github.com/notifications/beacon/AFR53GMNEFYRHTKMXROKQRTRYFVD7A5CNFSM4NN24OIKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOE2UC3CQ.gif>
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [cloudstack] rhtyd commented on issue #4118: com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool - Ceph Storage - ACS 4.13
Posted by GitBox <gi...@apache.org>.
rhtyd commented on issue #4118:
URL: https://github.com/apache/cloudstack/issues/4118#issuecomment-648555914
@ccycv can you try on 4.13.1.0 or 4.14.1.0? Are the ceph credentials correct, or was the storage pool not created on Ceph; or removed out-of-band in ceph-mgr?
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [cloudstack] rhtyd closed issue #4118: com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool - Ceph Storage - ACS 4.13
Posted by GitBox <gi...@apache.org>.
rhtyd closed issue #4118:
URL: https://github.com/apache/cloudstack/issues/4118
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [cloudstack] rhtyd commented on issue #4118: com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool - Ceph Storage - ACS 4.13
Posted by GitBox <gi...@apache.org>.
rhtyd commented on issue #4118:
URL: https://github.com/apache/cloudstack/issues/4118#issuecomment-672760482
Closing based on the last comment
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org