search

apache / cloudstack

Apache CloudStack is an opensource Infrastructure as a Service (IaaS) cloud computing platform
https://cloudstack.apache.org/
Apache License 2.0
2.05k stars 1.1k forks source link

unable to start secondary storage vm #7171

Closed MilanHofmann closed 1 year ago

MilanHofmann commented 1 year ago
ISSUE TYPE
COMPONENT NAME
Secondary Storage
CLOUDSTACK VERSION
4.17.2.0
CONFIGURATION

basic network

OS / ENVIRONMENT

ubuntu 22.04.1 Jammy Jellyfish

SUMMARY

system vm for secondary storage fails to start.

STEPS TO REPRODUCE

Add secondary NFS storage from management server to host via ui.

EXPECTED RESULTS

Host mounts secondary storage and downloads templates.

ACTUAL RESULTS

It fails in loop with the following logs 

2023-02-05 20:30:10,783 INFO  [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) (logid:) Attempting to create storage pool 19986357-feca-4161-830a-2a147fc59d9f (Filesystem) in libvirt
2023-02-05 20:30:10,788 ERROR [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) (logid:) Connection with libvirtd is broken: invalid connection pointer in virConnectGetVersion
2023-02-05 20:30:10,791 INFO  [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) (logid:) Found existing defined storage pool 19986357-feca-4161-830a-2a147fc59d9f, using it.
2023-02-05 20:30:10,792 INFO  [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) (logid:) Trying to fetch storage pool 19986357-feca-4161-830a-2a147fc59d9f from libvirt
2023-02-05 20:30:10,850 INFO  [cloud.serializer.GsonHelper] (Agent-Handler-1:null) (logid:) Default Builder inited.
2023-02-05 20:30:10,917 INFO  [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Process agent startup answer, agent id = 0
2023-02-05 20:30:10,917 INFO  [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Set agent id 0
2023-02-05 20:30:10,925 INFO  [cloud.agent.Agent] (Agent-Handler-2:null) (logid:) Startup Response Received: agent id = 0
2023-02-05 20:30:11,349 INFO  [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:093226eb) Processing agent ready command, agent id = 6
2023-02-05 20:30:11,351 INFO  [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:093226eb) Set agent id 6
2023-02-05 20:30:11,354 INFO  [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:093226eb) Ready command is processed for agent id = 6
2023-02-05 20:30:11,440 INFO  [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:093226eb) Processing agent ready command, agent id = 6
2023-02-05 20:30:11,441 INFO  [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:093226eb) Set agent id 6
2023-02-05 20:30:11,443 INFO  [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:093226eb) Processed new management server list: bla@static
2023-02-05 20:30:11,443 INFO  [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:093226eb) Ready command is processed for agent id = 6
2023-02-05 20:30:15,673 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:3c6c2894) Attempting to create storage pool 4301a675-8d2d-3842-8827-95a0e46475d1 (NetworkFilesystem) in libvirt
2023-02-05 20:30:15,694 WARN  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:3c6c2894) Storage pool 4301a675-8d2d-3842-8827-95a0e46475d1 was not found running in libvirt. Need to create it.
2023-02-05 20:30:15,695 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:3c6c2894) Didn't find an existing storage pool 4301a675-8d2d-3842-8827-95a0e46475d1 by UUID, checking for pools with duplicate paths
2023-02-05 20:30:16,295 INFO  [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:093b852c) No existing libvirtd connection found. Opening a new one
2023-02-05 20:30:16,298 WARN  [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:093b852c) Can not find a connection for Instance v-68-VM. Assuming the default connection.
2023-02-05 20:30:16,605 WARN  [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-5:null) (logid:093b852c) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied.
2023-02-05 20:30:16,605 WARN  [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-5:null) (logid:093b852c) Groovy scripting engine is not initialized. Data transformation skipped.
boring-cyborg[bot] commented 1 year ago

Thanks for opening your first issue here! Be sure to follow the issue template!

slavkap commented 1 year ago

@MilanHofmann, can you enable the debug level of the agent and share the complete log?

MilanHofmann commented 1 year ago

@slavkap Thank you for the quick response! Sure I'll attach the logs. Although the output is now slightly different after opening the right ports on the management server. agent.log

weizhouapache commented 1 year ago

@MilanHofmann it looks something wrong with the management server when create/start system vms.

slavkap commented 1 year ago

@MilanHofmann, according to the log, there isn't information why the system VM fails on start. There is a failure only for copying the systemvm template related to the NFS

org.libvirt.LibvirtException: internal error: Child process (/usr/bin/mount -o nodev,nosuid,noexec 3.70.229.74:/secondary/template/tmpl/1/3 /mnt/3d4d2066-74be-3b88-bc4b-81c01d3f4d5d) unexpected exit status 32: mount.nfs: Connection timed out

MilanHofmann commented 1 year ago

@slavkap Yes you are actually right. After providing the correct path the mount succeeded. But still the vms fail during the start. Cloud the problem be line 66? -> 2023-02-07 10:17:14,860 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-1:null) (logid:f1a221ad) Failed to backup cmdline file due to There was a problem while connecting to 169.254.146.170:3922 agent.log

MilanHofmann commented 1 year ago

Okay qemu was not installed. Sorry for bothering & thank you very much for your help!

MilanHofmann commented 1 year ago

Actually it did not resolve and the qemu installation was not the problem. Referring to the logs attached above: Does this mean the vm has not been created or is it a networking issue withkvm? Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'v-142-VM'

@weizhouapache could you reopen the issue?

MilanHofmann commented 1 year ago

Looks to me like no vm is actually beeing created and therefore is not reachable. Which also explains line 23 in the logs -> 2023-02-07 10:17:10,011 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:4e0c541e) VM v-129-VM doesn't exist, no need to stop it

image

weizhouapache commented 1 year ago

@MilanHofmann can you please share the management-server.log ?

MilanHofmann commented 1 year ago

@weizhouapache sure -> management-server.log

slavkap commented 1 year ago

@MilanHofmann, this log contains information from the agent.log

MilanHofmann commented 1 year ago

@slavkap Sorry! Here's the correct one. management-server.log

slavkap commented 1 year ago

it says that the pod is disabled 2023-02-07 14:25:11,760 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-75:ctx-482e1c4d job-441/job-517 ctx-e52fb184) (logid:2e150804) The cluster is in a disabled pod : 1

MilanHofmann commented 1 year ago

@slavkap But why does the UI say it is enabled then?

image

slavkap commented 1 year ago

Can you share the output of the following SQL queries:

select from cluster; select from host;

MilanHofmann commented 1 year ago

@slavkap mysql> select * from cluster\G; 1. row id: 1 name: contabo_test_cluster uuid: fc690d48-5e28-446d-bce5-71816590758f guid: c4ca4238-a0b9-3382-8dcc-509a6f75849b pod_id: 1 data_center_id: 1 hypervisor_type: KVM cluster_type: CloudManaged allocation_state: Enabled managed_state: Managed removed: NULL owner: NULL created: NULL lastUpdated: NULL engine_state: Disabled

select * from host\G;

1. row id: 1 name: m0995.contaboserver.net uuid: 153a3067-1f83-4367-b49e-36e6b8af4b68 status: Removed type: Routing private_ip_address: 79.143.179.221 private_netmask: 255.255.255.0 private_mac_address: 1c:6f:65:91:9e:86 storage_ip_address: 79.143.179.221 storage_netmask: 255.255.255.0 storage_mac_address: 1c:6f:65:91:9e:86 storage_ip_address_2: NULL storage_mac_address_2: NULL storage_netmask_2: NULL cluster_id: NULL public_ip_address: 79.143.179.221 public_netmask: 255.255.255.0 public_mac_address: 1c:6f:65:91:9e:86 proxy_port: NULL data_center_id: 1 pod_id: 1 cpu_sockets: 1 cpus: 12 speed: 3200 url: NULL fs_type: NULL hypervisor_type: KVM hypervisor_version: NULL ram: 24133316608 resource: NULL version: 4.17.2.0 parent: NULL total_size: NULL capabilities: hvm,snapshot guid: NULL available: 1 setup: 0 dom0_memory: 0 last_ping: 1636346792 mgmt_server_id: NULL disconnected: NULL created: 2023-02-05 17:45:15 removed: 2023-02-05 17:51:21 update_count: 4 resource_state: Disabled owner: NULL lastUpdated: NULL engine_state: Disabled 2. row id: 2 name: m0995.contaboserver.net uuid: c9d3ffb7-46bc-4361-8343-98bf76652239 status: Removed type: Routing private_ip_address: 79.143.179.221 private_netmask: 255.255.255.0 private_mac_address: 1c:6f:65:91:9e:86 storage_ip_address: 79.143.179.221 storage_netmask: 255.255.255.0 storage_mac_address: 1c:6f:65:91:9e:86 storage_ip_address_2: NULL storage_mac_address_2: NULL storage_netmask_2: NULL cluster_id: NULL public_ip_address: 79.143.179.221 public_netmask: 255.255.255.0 public_mac_address: 1c:6f:65:91:9e:86 proxy_port: NULL data_center_id: 1 pod_id: 1 cpu_sockets: 1 cpus: 12 speed: 3200 url: NULL fs_type: NULL hypervisor_type: KVM hypervisor_version: NULL ram: 24133316608 resource: NULL version: 4.17.2.0 parent: NULL total_size: NULL capabilities: hvm,snapshot guid: NULL available: 1 setup: 0 dom0_memory: 0 last_ping: 1636347592 mgmt_server_id: NULL disconnected: NULL created: 2023-02-05 17:58:20 removed: 2023-02-05 18:02:33 update_count: 7 resource_state: Disabled owner: NULL lastUpdated: NULL engine_state: Disabled 3. row id: 3 name: m0995.contaboserver.net uuid: 9410b8b2-8a62-4a4a-9ece-8a5d765a2d42 status: Removed type: Routing private_ip_address: 79.143.179.221 private_netmask: 255.255.255.0 private_mac_address: 1c:6f:65:91:9e:86 storage_ip_address: 79.143.179.221 storage_netmask: 255.255.255.0 storage_mac_address: 1c:6f:65:91:9e:86 storage_ip_address_2: NULL storage_mac_address_2: NULL storage_netmask_2: NULL cluster_id: NULL public_ip_address: 79.143.179.221 public_netmask: 255.255.255.0 public_mac_address: 1c:6f:65:91:9e:86 proxy_port: NULL data_center_id: 1 pod_id: 1 cpu_sockets: 1 cpus: 12 speed: 3200 url: NULL fs_type: NULL hypervisor_type: KVM hypervisor_version: NULL ram: 24133316608 resource: NULL version: 4.17.2.0 parent: NULL total_size: NULL capabilities: hvm,snapshot guid: NULL available: 1 setup: 0 dom0_memory: 0 last_ping: 1636347849 mgmt_server_id: NULL disconnected: NULL created: 2023-02-05 18:03:18 removed: 2023-02-05 18:16:41 update_count: 4 resource_state: Disabled owner: NULL lastUpdated: NULL engine_state: Disabled 4. row id: 4 name: m0995.contaboserver.net uuid: ee605607-3ec7-46a1-8298-e5d2e4e7807e status: Removed type: Routing private_ip_address: 79.143.179.221 private_netmask: 255.255.255.0 private_mac_address: 1c:6f:65:91:9e:86 storage_ip_address: 79.143.179.221 storage_netmask: 255.255.255.0 storage_mac_address: 1c:6f:65:91:9e:86 storage_ip_address_2: NULL storage_mac_address_2: NULL storage_netmask_2: NULL cluster_id: NULL public_ip_address: 79.143.179.221 public_netmask: 255.255.255.0 public_mac_address: 1c:6f:65:91:9e:86 proxy_port: NULL data_center_id: 1 pod_id: 1 cpu_sockets: 1 cpus: 12 speed: 3200 url: NULL fs_type: NULL hypervisor_type: KVM hypervisor_version: NULL ram: 24133316608 resource: NULL version: 4.17.2.0 parent: NULL total_size: NULL capabilities: hvm,snapshot guid: NULL available: 1 setup: 0 dom0_memory: 0 last_ping: 1636348692 mgmt_server_id: NULL disconnected: NULL created: 2023-02-05 18:17:41 removed: 2023-02-05 18:21:34 update_count: 4 resource_state: Disabled owner: NULL lastUpdated: NULL engine_state: Disabled 5. row id: 5 name: m0995.contaboserver.net uuid: b8b9ca48-878f-4d8b-bcd9-ebe126173806 status: Removed type: Routing private_ip_address: 79.143.179.221 private_netmask: 255.255.255.0 private_mac_address: 1c:6f:65:91:9e:86 storage_ip_address: 79.143.179.221 storage_netmask: 255.255.255.0 storage_mac_address: 1c:6f:65:91:9e:86 storage_ip_address_2: NULL storage_mac_address_2: NULL storage_netmask_2: NULL cluster_id: NULL public_ip_address: 79.143.179.221 public_netmask: 255.255.255.0 public_mac_address: 1c:6f:65:91:9e:86 proxy_port: NULL data_center_id: 1 pod_id: 1 cpu_sockets: 1 cpus: 12 speed: 3200 url: NULL fs_type: NULL hypervisor_type: KVM hypervisor_version: NULL ram: 24133316608 resource: NULL version: 4.17.2.0 parent: NULL total_size: NULL capabilities: hvm,snapshot guid: NULL available: 1 setup: 0 dom0_memory: 0 last_ping: 1636348988 mgmt_server_id: NULL disconnected: NULL created: 2023-02-05 18:22:44 removed: 2023-02-05 19:28:47 update_count: 4 resource_state: Disabled owner: NULL lastUpdated: NULL engine_state: Disabled 6. row id: 6 name: m0995.contaboserver.net uuid: 17de026e-9aeb-4c02-a8eb-162995206f89 status: Removed type: Routing private_ip_address: 79.143.179.221 private_netmask: 255.255.255.0 private_mac_address: 1c:6f:65:91:9e:86 storage_ip_address: 79.143.179.221 storage_netmask: 255.255.255.0 storage_mac_address: 1c:6f:65:91:9e:86 storage_ip_address_2: NULL storage_mac_address_2: NULL storage_netmask_2: NULL cluster_id: NULL public_ip_address: 79.143.179.221 public_netmask: 255.255.255.0 public_mac_address: 1c:6f:65:91:9e:86 proxy_port: NULL data_center_id: 1 pod_id: 1 cpu_sockets: 1 cpus: 12 speed: 3200 url: NULL fs_type: NULL hypervisor_type: KVM hypervisor_version: NULL ram: 24133316608 resource: NULL version: 4.17.2.0 parent: NULL total_size: NULL capabilities: hvm,snapshot guid: NULL available: 1 setup: 0 dom0_memory: 0 last_ping: 1636423998 mgmt_server_id: NULL disconnected: NULL created: 2023-02-05 19:29:37 removed: 2023-02-06 18:31:51 update_count: 7 resource_state: Disabled owner: NULL lastUpdated: NULL engine_state: Disabled 7. row id: 7 name: m0995.contaboserver.net uuid: b9cc9299-b2ff-4494-ad47-ebd221dfe102 status: Up type: Routing private_ip_address: 79.143.179.221 private_netmask: 255.255.255.0 private_mac_address: 1c:6f:65:91:9e:86 storage_ip_address: 79.143.179.221 storage_netmask: 255.255.255.0 storage_mac_address: 1c:6f:65:91:9e:86 storage_ip_address_2: NULL storage_mac_address_2: NULL storage_netmask_2: NULL cluster_id: 1 public_ip_address: 79.143.179.221 public_netmask: 255.255.255.0 public_mac_address: 1c:6f:65:91:9e:86 proxy_port: NULL data_center_id: 1 pod_id: 1 cpu_sockets: 1 cpus: 12 speed: 3200 url: NULL fs_type: NULL hypervisor_type: KVM hypervisor_version: NULL ram: 24133316608 resource: NULL version: 4.17.2.0 parent: NULL total_size: NULL capabilities: hvm,snapshot guid: 67284449-f954-3204-afdc-1057f885b1a2-LibvirtComputingResource available: 1 setup: 0 dom0_memory: 0 last_ping: 1636496471 mgmt_server_id: 2934858251578 disconnected: NULL created: 2023-02-06 18:33:23 removed: NULL update_count: 7 resource_state: Enabled owner: NULL lastUpdated: NULL engine_state: Disabled

MilanHofmann commented 1 year ago

@slavkap I actually find this line from the logs interesting: com.cloud.exception.StorageUnavailableException: Resource [StoragePool:7] is unreachable: Unable to create Vol[164|vm=164|ROOT]:Failed to get template from pool: 73d1d51a-7a3a-3643-833c-a828041be576

If I mount the secondary storage on the host manually the image is available. But once it's being mounted by cloudstack itself the directory is empty. Here are the agent logs:

` 2023-02-07 19:18:12,457 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:40b6260a) Request:Seq 7-1562186120744141630: { Cmd , MgmtId: 2934858251578, via: 7, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/1/3/","origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":"3","format":"QCOW2","accountId":"1","checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://3.70.229.74/export/secondary","_role":"Image"}},"name":"routing-3","size":"(0 bytes) 0","hypervisorType":"KVM","bootable":"false","uniqueName":"routing-3","directDownload":"false","deployAsIs":"false"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":"3","format":"QCOW2","accountId":"1","checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"19986357-feca-4161-830a-2a147fc59d9f","name":"m0995.contaboserver.net-local-19986357","id":"7","poolType":"Filesystem","host":"79.143.179.221","path":"/var/lib/libvirt/images","port":"0","url":"Filesystem://79.143.179.221/var/lib/libvirt/images/?ROLE=Primary&STOREUUID=19986357-feca-4161-830a-2a147fc59d9f","isManaged":"false"}},"name":"routing-3","size":"(0 bytes) 0","hypervisorType":"KVM","bootable":"false","uniqueName":"routing-3","directDownload":"false","deployAsIs":"false"}},"executeInSequence":"true","options":{},"options2":{},"wait":"10800","bypassHostMaintenance":"false"}}] } 2023-02-07 19:18:12,457 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:40b6260a) Processing command: org.apache.cloudstack.storage.command.CopyCommand 2023-02-07 19:18:12,457 DEBUG [storage.resource.StorageSubsystemCommandHandlerBase] (agentRequest-Handler-4:null) (logid:40b6260a) Executing command CopyCommand: [{"srcTO":{"path":"template/tmpl/1/3/","origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":3,"format":"QCOW2","accountId":1,"checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"_url":"nfs://3.70.229.74/export/secondary","_role":"Image"},"name":"routing-3","size":0,"hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"destTO":{"origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":3,"format":"QCOW2","accountId":1,"checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"uuid":"19986357-feca-4161-830a-2a147fc59d9f","name":"m0995.contaboserver.net-local-19986357","id":7,"poolType":"Filesystem","host":"79.143.179.221","path":"/var/lib/libvirt/images","port":0,"url":"Filesystem://79.143.179.221/var/lib/libvirt/images/?ROLE\u003dPrimary\u0026STOREUUID\u003d19986357-feca-4161-830a-2a147fc59d9f","isManaged":false},"name":"routing-3","size":0,"hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"executeInSequence":true,"options":{},"options2":{},"contextMap":{"logid":"40b6260a","job":"job-440/job-548"},"wait":10800,"bypassHostMaintenance":false}]. 2023-02-07 19:18:12,457 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Attempting to create storage pool 73d1d51a-7a3a-3643-833c-a828041be576 (NetworkFilesystem) in libvirt 2023-02-07 19:18:12,457 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-4:null) (logid:40b6260a) Looking for libvirtd connection at: qemu:///system 2023-02-07 19:18:12,477 WARN [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Storage pool 73d1d51a-7a3a-3643-833c-a828041be576 was not found running in libvirt. Need to create it. 2023-02-07 19:18:12,477 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Didn't find an existing storage pool 73d1d51a-7a3a-3643-833c-a828041be576 by UUID, checking for pools with duplicate paths 2023-02-07 19:18:12,478 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Checking path of existing pool 19986357-feca-4161-830a-2a147fc59d9f against pool we want to create 2023-02-07 19:18:12,481 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Attempting to create storage pool 73d1d51a-7a3a-3643-833c-a828041be576 2023-02-07 19:18:12,481 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a)

73d1d51a-7a3a-3643-833c-a828041be576 73d1d51a-7a3a-3643-833c-a828041be576

/mnt/73d1d51a-7a3a-3643-833c-a828041be576

2023-02-07 19:18:12,481 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:40b6260a) Executing: /bin/bash -c mountpoint -q /mnt/73d1d51a-7a3a-3643-833c-a828041be576 2023-02-07 19:18:12,482 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:40b6260a) Executing while with timeout : 3600000 2023-02-07 19:18:12,485 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:40b6260a) Execution is successful. 2023-02-07 19:18:12,486 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Attempting to unmount old mount at /mnt/73d1d51a-7a3a-3643-833c-a828041be576 2023-02-07 19:18:12,486 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:40b6260a) Executing: /bin/bash -c umount -l /mnt/73d1d51a-7a3a-3643-833c-a828041be576 2023-02-07 19:18:12,487 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:40b6260a) Executing while with timeout : 3600000 2023-02-07 19:18:12,493 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:40b6260a) Execution is successful. 2023-02-07 19:18:12,494 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Succeeded in unmounting /mnt/73d1d51a-7a3a-3643-833c-a828041be576 2023-02-07 19:18:12,721 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Trying to fetch storage pool 73d1d51a-7a3a-3643-833c-a828041be576 from libvirt 2023-02-07 19:18:12,721 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-4:null) (logid:40b6260a) Looking for libvirtd connection at: qemu:///system 2023-02-07 19:18:12,750 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Successfully refreshed pool 73d1d51a-7a3a-3643-833c-a828041be576 Capacity: (242.11 GB) 259962437632 Used: (9.25 GB) 9930014720 Available: (232.86 GB) 250032422912 2023-02-07 19:18:12,799 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Attempting to remove storage pool 73d1d51a-7a3a-3643-833c-a828041be576 from libvirt 2023-02-07 19:18:12,799 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-4:null) (logid:40b6260a) Looking for libvirtd connection at: qemu:///system 2023-02-07 19:18:12,817 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Storage pool 73d1d51a-7a3a-3643-833c-a828041be576 has no corresponding secret. Not removing any secret. 2023-02-07 19:18:12,826 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:40b6260a) Storage pool 73d1d51a-7a3a-3643-833c-a828041be576 was successfully removed from libvirt. 2023-02-07 19:18:12,826 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:40b6260a) Seq 7-1562186120744141630: { Ans: , MgmtId: 2934858251578, via: 7, Ver: v1, Flags: 110, [{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":"(0 bytes) 0","result":"false","details":"Failed to get template from pool: 73d1d51a-7a3a-3643-833c-a828041be576","wait":"0","bypassHostMaintenance":"false"}}] } 2023-02-07 19:18:12,910 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:40b6260a) Request:Seq 7-1562186120744141631: { Cmd , MgmtId: 2934858251578, via: 7, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","controlIp":"169.254.117.245","forceStop":"false","volumesToDisconnect":[],"vmName":"v-174-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] } 2023-02-07 19:18:12,911 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:40b6260a) Processing command: com.cloud.agent.api.StopCommand 2023-02-07 19:18:12,911 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-5:null) (logid:40b6260a) backing up the cmdline 2023-02-07 19:18:15,972 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-5:null) (logid:40b6260a) Failed to backup cmdline file due to There was a problem while connecting to 169.254.117.245:3922 2023-02-07 19:18:15,972 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:40b6260a) Looking for libvirtd connection at: qemu:///system 2023-02-07 19:18:15,993 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:40b6260a) Can not find KVM connection for Instance: v-174-VM, continuing. 2023-02-07 19:18:15,993 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:40b6260a) Looking for libvirtd connection at: lxc:/// 2023-02-07 19:18:15,993 INFO [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:40b6260a) No existing libvirtd connection found. Opening a new one 2023-02-07 19:18:15,994 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:40b6260a) Can not find LXC connection for Instance: v-174-VM, continuing. 2023-02-07 19:18:15,994 WARN [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:40b6260a) Can not find a connection for Instance v-174-VM. Assuming the default connection. 2023-02-07 19:18:15,995 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:40b6260a) Looking for libvirtd connection at: qemu:///system 2023-02-07 19:18:16,013 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:40b6260a) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'v-174-VM' 2023-02-07 19:18:16,013 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:40b6260a) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'v-174-VM' 2023-02-07 19:18:16,014 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:40b6260a) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'v-174-VM' 2023-02-07 19:18:16,014 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:40b6260a) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname v-174-VM 2023-02-07 19:18:16,015 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:40b6260a) Executing while with timeout : 1800000 2023-02-07 19:18:16,113 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:40b6260a) Execution is successful. 2023-02-07 19:18:16,114 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:40b6260a) Failed to get vm :Domain not found: no domain with matching name 'v-174-VM' 2023-02-07 19:18:16,114 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:40b6260a) Try to stop the vm at first 2023-02-07 19:18:16,115 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:40b6260a) VM v-174-VM doesn't exist, no need to stop it `

MilanHofmann commented 1 year ago

@slavkap if I create the pool manually and mount the secondary storage to it's source directory the agent still fails to get the template. Although it is the source directory. image

What I understand from the logs is this part: 2023-02-07 20:25:42,602 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Storage pool 73d1d51a-7a3a-3643-833c-a828041be576 was successfully removed from libvirt. 2023-02-07 20:25:42,603 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:40b6260a) Seq 7-1562186120744141803: { Ans: , MgmtId: 2934858251578, via: 7, Ver: v1, Flags: 110, [{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":"(0 bytes) 0","result":"false","details":"Failed to get template from pool: 73d1d51a-7a3a-3643-833c-a828041be576","wait":"0","bypassHostMaintenance":"false"}}] } `

Why is the storage pool removed from libvirt before trying to access it?

Here are complete the agent logs (starting from where I created the pool manually): 2023-02-07 20:25:42,470 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:40b6260a) Request:Seq 7-1562186120744141803: { Cmd , MgmtId: 2934858251578, via: 7, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/1/3/","origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":"3","format":"QCOW2","accountId":"1","checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://3.70.229.74/export/secondary","_role":"Image"}},"name":"routing-3","size":"(0 bytes) 0","hypervisorType":"KVM","bootable":"false","uniqueName":"routing-3","directDownload":"false","deployAsIs":"false"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":"3","format":"QCOW2","accountId":"1","checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"19986357-feca-4161-830a-2a147fc59d9f","name":"m0995.contaboserver.net-local-19986357","id":"7","poolType":"Filesystem","host":"79.143.179.221","path":"/var/lib/libvirt/images","port":"0","url":"Filesystem://79.143.179.221/var/lib/libvirt/images/?ROLE=Primary&STOREUUID=19986357-feca-4161-830a-2a147fc59d9f","isManaged":"false"}},"name":"routing-3","size":"(0 bytes) 0","hypervisorType":"KVM","bootable":"false","uniqueName":"routing-3","directDownload":"false","deployAsIs":"false"}},"executeInSequence":"true","options":{},"options2":{},"wait":"10800","bypassHostMaintenance":"false"}}] } 2023-02-07 20:25:42,470 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:40b6260a) Processing command: org.apache.cloudstack.storage.command.CopyCommand 2023-02-07 20:25:42,470 DEBUG [storage.resource.StorageSubsystemCommandHandlerBase] (agentRequest-Handler-3:null) (logid:40b6260a) Executing command CopyCommand: [{"srcTO":{"path":"template/tmpl/1/3/","origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":3,"format":"QCOW2","accountId":1,"checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"_url":"nfs://3.70.229.74/export/secondary","_role":"Image"},"name":"routing-3","size":0,"hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"destTO":{"origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":3,"format":"QCOW2","accountId":1,"checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"uuid":"19986357-feca-4161-830a-2a147fc59d9f","name":"m0995.contaboserver.net-local-19986357","id":7,"poolType":"Filesystem","host":"79.143.179.221","path":"/var/lib/libvirt/images","port":0,"url":"Filesystem://79.143.179.221/var/lib/libvirt/images/?ROLE\u003dPrimary\u0026STOREUUID\u003d19986357-feca-4161-830a-2a147fc59d9f","isManaged":false},"name":"routing-3","size":0,"hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"executeInSequence":true,"options":{},"options2":{},"contextMap":{"logid":"40b6260a","job":"job-440/job-594"},"wait":10800,"bypassHostMaintenance":false}]. 2023-02-07 20:25:42,471 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Attempting to create storage pool 73d1d51a-7a3a-3643-833c-a828041be576 (NetworkFilesystem) in libvirt 2023-02-07 20:25:42,471 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:40b6260a) Looking for libvirtd connection at: qemu:///system 2023-02-07 20:25:42,489 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Found existing defined storage pool 73d1d51a-7a3a-3643-833c-a828041be576, using it. 2023-02-07 20:25:42,490 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Trying to fetch storage pool 73d1d51a-7a3a-3643-833c-a828041be576 from libvirt 2023-02-07 20:25:42,490 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:40b6260a) Looking for libvirtd connection at: qemu:///system 2023-02-07 20:25:42,514 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Successfully refreshed pool 73d1d51a-7a3a-3643-833c-a828041be576 Capacity: (242.11 GB) 259962437632 Used: (9.25 GB) 9936830464 Available: (232.85 GB) 250025607168 2023-02-07 20:25:42,582 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Attempting to remove storage pool 73d1d51a-7a3a-3643-833c-a828041be576 from libvirt 2023-02-07 20:25:42,582 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:40b6260a) Looking for libvirtd connection at: qemu:///system 2023-02-07 20:25:42,601 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Storage pool 73d1d51a-7a3a-3643-833c-a828041be576 has no corresponding secret. Not removing any secret. 2023-02-07 20:25:42,602 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Storage pool 73d1d51a-7a3a-3643-833c-a828041be576 was successfully removed from libvirt. 2023-02-07 20:25:42,603 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:40b6260a) Seq 7-1562186120744141803: { Ans: , MgmtId: 2934858251578, via: 7, Ver: v1, Flags: 110, [{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":"(0 bytes) 0","result":"false","details":"Failed to get template from pool: 73d1d51a-7a3a-3643-833c-a828041be576","wait":"0","bypassHostMaintenance":"false"}}] } 2023-02-07 20:25:42,696 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:40b6260a) Request:Seq 7-1562186120744141804: { Cmd , MgmtId: 2934858251578, via: 7, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","controlIp":"169.254.127.45","forceStop":"false","volumesToDisconnect":[],"vmName":"v-190-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] } 2023-02-07 20:25:42,696 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:40b6260a) Processing command: com.cloud.agent.api.StopCommand 2023-02-07 20:25:42,696 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-4:null) (logid:40b6260a) backing up the cmdline `

slavkap commented 1 year ago

@MilanHofmann, is this a fresh install? If it is, could you let me know if you followed the step for preparing the system VM template? You should not have those file formats in the secondary storage directory. If the system VM template is seeded correctly you should have something like this:

ls /export/testnfs/template/tmpl/1/3/

d8e9c766-9cfd-4190-987e-d6338c4ea381.qcow2  template.properties

cat /export/testnfs/template/tmpl/1/3/template.properties 

filename=d8e9c766-9cfd-4190-987e-d6338c4ea381.qcow2
description=SystemVM Template
hvm=false
size=460521472
qcow2=true
id=3
public=true
qcow2.filename=d8e9c766-9cfd-4190-987e-d6338c4ea381.qcow2
uniquename=routing-3
qcow2.virtualsize=5242880000
virtualsize=5242880000
qcow2.size=460521472
weizhouapache commented 1 year ago

@slavkap if I create the pool manually and mount the secondary storage to it's source directory the agent still fails to get the template. Although it is the source directory. image

What I understand from the logs is this part: 2023-02-07 20:25:42,602 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Storage pool 73d1d51a-7a3a-3643-833c-a828041be576 was successfully removed from libvirt. 2023-02-07 20:25:42,603 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:40b6260a) Seq 7-1562186120744141803: { Ans: , MgmtId: 2934858251578, via: 7, Ver: v1, Flags: 110, [{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":"(0 bytes) 0","result":"false","details":"Failed to get template from pool: 73d1d51a-7a3a-3643-833c-a828041be576","wait":"0","bypassHostMaintenance":"false"}}] } `

Why is the storage pool removed from libvirt before trying to access it?

Here are complete the agent logs (starting from where I created the pool manually): 2023-02-07 20:25:42,470 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:40b6260a) Request:Seq 7-1562186120744141803: { Cmd , MgmtId: 2934858251578, via: 7, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/1/3/","origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":"3","format":"QCOW2","accountId":"1","checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://3.70.229.74/export/secondary","_role":"Image"}},"name":"routing-3","size":"(0 bytes) 0","hypervisorType":"KVM","bootable":"false","uniqueName":"routing-3","directDownload":"false","deployAsIs":"false"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":"3","format":"QCOW2","accountId":"1","checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"19986357-feca-4161-830a-2a147fc59d9f","name":"m0995.contaboserver.net-local-19986357","id":"7","poolType":"Filesystem","host":"79.143.179.221","path":"/var/lib/libvirt/images","port":"0","url":"Filesystem://79.143.179.221/var/lib/libvirt/images/?ROLE=Primary&STOREUUID=19986357-feca-4161-830a-2a147fc59d9f","isManaged":"false"}},"name":"routing-3","size":"(0 bytes) 0","hypervisorType":"KVM","bootable":"false","uniqueName":"routing-3","directDownload":"false","deployAsIs":"false"}},"executeInSequence":"true","options":{},"options2":{},"wait":"10800","bypassHostMaintenance":"false"}}] } 2023-02-07 20:25:42,470 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:40b6260a) Processing command: org.apache.cloudstack.storage.command.CopyCommand 2023-02-07 20:25:42,470 DEBUG [storage.resource.StorageSubsystemCommandHandlerBase] (agentRequest-Handler-3:null) (logid:40b6260a) Executing command CopyCommand: [{"srcTO":{"path":"template/tmpl/1/3/","origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":3,"format":"QCOW2","accountId":1,"checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"_url":"nfs://3.70.229.74/export/secondary","_role":"Image"},"name":"routing-3","size":0,"hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"destTO":{"origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.2-kvm.qcow2.bz2","uuid":"df635688-a32e-11ed-a71b-02ab532efd3a","id":3,"format":"QCOW2","accountId":1,"checksum":"0e44e12e0a6a370b85d5d7f2ad541354","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"uuid":"19986357-feca-4161-830a-2a147fc59d9f","name":"m0995.contaboserver.net-local-19986357","id":7,"poolType":"Filesystem","host":"79.143.179.221","path":"/var/lib/libvirt/images","port":0,"url":"Filesystem://79.143.179.221/var/lib/libvirt/images/?ROLE\u003dPrimary\u0026STOREUUID\u003d19986357-feca-4161-830a-2a147fc59d9f","isManaged":false},"name":"routing-3","size":0,"hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"executeInSequence":true,"options":{},"options2":{},"contextMap":{"logid":"40b6260a","job":"job-440/job-594"},"wait":10800,"bypassHostMaintenance":false}]. 2023-02-07 20:25:42,471 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Attempting to create storage pool 73d1d51a-7a3a-3643-833c-a828041be576 (NetworkFilesystem) in libvirt 2023-02-07 20:25:42,471 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:40b6260a) Looking for libvirtd connection at: qemu:///system 2023-02-07 20:25:42,489 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Found existing defined storage pool 73d1d51a-7a3a-3643-833c-a828041be576, using it. 2023-02-07 20:25:42,490 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Trying to fetch storage pool 73d1d51a-7a3a-3643-833c-a828041be576 from libvirt 2023-02-07 20:25:42,490 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:40b6260a) Looking for libvirtd connection at: qemu:///system 2023-02-07 20:25:42,514 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Successfully refreshed pool 73d1d51a-7a3a-3643-833c-a828041be576 Capacity: (242.11 GB) 259962437632 Used: (9.25 GB) 9936830464 Available: (232.85 GB) 250025607168 2023-02-07 20:25:42,582 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Attempting to remove storage pool 73d1d51a-7a3a-3643-833c-a828041be576 from libvirt 2023-02-07 20:25:42,582 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:40b6260a) Looking for libvirtd connection at: qemu:///system 2023-02-07 20:25:42,601 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Storage pool 73d1d51a-7a3a-3643-833c-a828041be576 has no corresponding secret. Not removing any secret. 2023-02-07 20:25:42,602 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:40b6260a) Storage pool 73d1d51a-7a3a-3643-833c-a828041be576 was successfully removed from libvirt. 2023-02-07 20:25:42,603 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:40b6260a) Seq 7-1562186120744141803: { Ans: , MgmtId: 2934858251578, via: 7, Ver: v1, Flags: 110, [{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":"(0 bytes) 0","result":"false","details":"Failed to get template from pool: 73d1d51a-7a3a-3643-833c-a828041be576","wait":"0","bypassHostMaintenance":"false"}}] } 2023-02-07 20:25:42,696 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:40b6260a) Request:Seq 7-1562186120744141804: { Cmd , MgmtId: 2934858251578, via: 7, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","controlIp":"169.254.127.45","forceStop":"false","volumesToDisconnect":[],"vmName":"v-190-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] } 2023-02-07 20:25:42,696 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:40b6260a) Processing command: com.cloud.agent.api.StopCommand 2023-02-07 20:25:42,696 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-4:null) (logid:40b6260a) backing up the cmdline `

it seems the directory does not contain a image for systemvm template on kvm.

MilanHofmann commented 1 year ago

@slavkap @weizhouapache Yes that was the problem! Thank you so much for taking the time to help me! I am completely new to Cloudstack - please let me know once I bother you too much.

Now there's some problem with my bridge config: agent.log

2023-02-08 08:17:16,503 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) (logid:40b6260a) iptables v1.8.7 (nf_tables): chainBF-cloudbr0' in table `filter' is incompatible, use 'nft' tool.

iptables v1.8.7 (nf_tables): chain BF-cloudbr0-OUT' in tablefilter' is incompatible, use 'nft' tool.

iptables v1.8.7 (nf_tables): chain BF-cloudbr0-IN' in tablefilter' is incompatible, use 'nft' tool.

ip6tables v1.8.7 (nf_tables): chain BF-cloudbr0' in tablefilter' is incompatible, use 'nft' tool.

ip6tables v1.8.7 (nf_tables): chain BF-cloudbr0-OUT' in tablefilter' is incompatible, use 'nft' tool.

ip6tables v1.8.7 (nf_tables): chain BF-cloudbr0-IN' in tablefilter' is incompatible, use 'nft' tool. `

weizhouapache commented 1 year ago

BF-cloudbr0-IN

@MilanHofmann

what's the nftables and iptables version ?

stop service nftables and retry ?

MilanHofmann commented 1 year ago

@weizhouapache Yes that solved the issue, thanx! But still the VM is not reachable: 2023-02-08 12:47:10,383 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:2e150804) Can not find KVM connection for Instance: s-210-VM, continuing. 2023-02-08 12:47:10,384 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:2e150804) Looking for libvirtd connection at: lxc:/// 2023-02-08 12:47:10,384 INFO [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:2e150804) No existing libvirtd connection found. Opening a new one 2023-02-08 12:47:10,385 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:2e150804) Can not find LXC connection for Instance: s-210-VM, continuing. 2023-02-08 12:47:10,386 WARN [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:2e150804) Can not find a connection for Instance s-210-VM. Assuming the default connection. 2023-02-08 12:47:10,386 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:2e150804) Looking for libvirtd connection at: qemu:///system 2023-02-08 12:47:10,403 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:2e150804) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 's-210-VM' 2023-02-08 12:47:10,404 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:2e150804) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 's-210-VM' 2023-02-08 12:47:10,405 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:2e150804) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 's-210-VM' 2023-02-08 12:47:10,405 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:2e150804) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname s-210-VM 2023-02-08 12:47:10,406 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:2e150804) Executing while with timeout : 1800000 2023-02-08 12:47:10,504 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:2e150804) Execution is successful. 2023-02-08 12:47:10,506 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:2e150804) Failed to get vm :Domain not found: no domain with matching name 's-210-VM' 2023-02-08 12:47:10,506 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:2e150804) Try to stop the vm at first 2023-02-08 12:47:10,507 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:2e150804) VM s-210-VM doesn't exist, no need to stop it agent.log

Anyway here are my iptables + nftables versions: Package: iptables Version: 1.8.7-1ubuntu5 Priority: standard Section: net Origin: Ubuntu Maintainer: Ubuntu Developers <ubuntu-devel-discuss@lists.ubuntu.com> Original-Maintainer: Debian Netfilter Packaging Team <pkg-netfilter-team@lists.alioth.debian.org> Bugs: https://bugs.launchpad.net/ubuntu/+filebug Installed-Size: 2905 kB Depends: libip4tc2 (= 1.8.7-1ubuntu5), libip6tc2 (= 1.8.7-1ubuntu5), libxtables12 (= 1.8.7-1ubuntu5), netbase (>= 6.0), libc6 (>= 2.34), libmnl0 (>= 1.0.3-4~), libnetfilter-conntrack3 (>= 1.0.6), libnfnetlink0, libnftnl11 (>= 1.1.5) Suggests: firewalld, kmod, nftables Breaks: iptables-nftables-compat (<< 1.6.2~) Replaces: iptables-nftables-compat (<< 1.6.2~) Homepage: https://www.netfilter.org/ Task: standard Download-Size: 455 kB APT-Manual-Installed: yes APT-Sources: http://asi-fs-m.contabo.net/ubuntu jammy/main amd64 Packages Description: administration tools for packet filtering and NAT The iptables/xtables framework has been replaced by nftables. You should consider migrating now. . iptables is the userspace command line program used to configure the Linux packet filtering and NAT ruleset. It is targeted towards systems and networks administrators. . This package contains several different utilities, the most important ones: . iptables-nft, iptables-nft-save, iptables-nft-restore (nft-based version) . iptables-legacy, iptables-legacy-save, iptables-legacy-restore (legacy version) . ip6tables-nft, ip6tables-nft-save, ip6tables-nft-restore (nft-based version) . ip6tables-legacy, ip6tables-legacy-save, ip6tables-legacy-restore (legacy version) . arptables-nft, arptables-nft-save, arptables-nft-restore (nft-based version) . ebtables-nft, ebtables-nft-save, ebtables-nft-restore (nft-based version)

+ Package: nftables Version: 1.0.2-1ubuntu3 Priority: standard Section: net Origin: Ubuntu Maintainer: Ubuntu Developers <ubuntu-devel-discuss@lists.ubuntu.com> Original-Maintainer: Debian Netfilter Packaging Team <pkg-netfilter-team@lists.alioth.debian.org> Bugs: https://bugs.launchpad.net/ubuntu/+filebug Installed-Size: 181 kB Depends: libnftables1 (= 1.0.2-1ubuntu3), libc6 (>= 2.34), libedit2 (>= 3.1-20130611-0) Recommends: netbase Suggests: firewalld Homepage: https://www.netfilter.org/ Task: standard Download-Size: 67.2 kB APT-Manual-Installed: no APT-Sources: http://asi-fs-m.contabo.net/ubuntu jammy-updates/main amd64 Packages Description: Program to control packet filtering rules by Netfilter project This software provides an in-kernel packet classification framework that is based on a network-specific Virtual Machine (VM) and the nft userspace command line tool. The nftables framework reuses the existing Netfilter subsystems such as the existing hook infrastructure, the connection tracking system, NAT, userspace queueing and logging subsystem. . nftables replaces the old popular iptables, ip6tables, arptables and ebtables. . Netfilter software and nftables in particular are used in applications such as Internet connection sharing, firewalls, IP accounting, transparent proxying, advanced routing and traffic control. . A Linux kernel >= 3.13 is required. However, >= 4.14 is recommended. `

weizhouapache commented 1 year ago

@MilanHofmann you may need to check management-server.log to find out why the s-210-VM does not exist on host. it might be caused by some exceptions during vm creation or start.

MilanHofmann commented 1 year ago

@weizhouapache Thanx again. Just checked management-server.log and I believe line 144 is the problem: com.cloud.exception.InsufficientAddressCapacityException: Insufficient address capacityScope I know that my host only has one public IP-Address available. I get from here that for each VM one public IP is allocated -> http://docs.cloudstack.apache.org/en/latest/adminguide/virtual_machines.html

So I guess I'll go with the advanced network then!