CPVM/SSVM fails to start on KVM/Ubuntu 22.04 with 4.19.1 RC1 using local storage

[yadvr]

Upon upgrading my env to 4.19.1 RC1 (from 4.19.0.2), on destroying systemvms, one of them wouldn't come up (SSVM & CPVM, I had more CPVM failures) which fails due to the following seen on the agent logs:

2024-07-11 15:37:46,746 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:fc1036c0) Trying to fetch storage pool 8aa9768c-cbcf-4e8e-8875-f94a7f9445b6 from libvirt
2024-07-11 15:37:46,747 WARN  [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:fc1036c0) Caught:
com.cloud.utils.exception.CloudRuntimeException: Could not fetch storage pool 8aa9768c-cbcf-4e8e-8875-f94a7f9445b6 from libvirt due to org.libvirt.LibvirtException: Storage pool not found: no storage pool with matching uuid '8aa9768c-cbcf-4e8e-8875-f94a7f9445b6'
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool(KVMStoragePoolManager.java:280)
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool(KVMStoragePoolManager.java:266)
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.disconnectPhysicalDisksViaVmSpec(KVMStoragePoolManager.java:241)
        at com.cloud.hypervisor.kvm.resource.wrapper.LibvirtStartCommandWrapper.execute(LibvirtStartCommandWrapper.java:160)
        at com.cloud.hypervisor.kvm.resource.wrapper.LibvirtStartCommandWrapper.execute(LibvirtStartCommandWrapper.java:49)
        at com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1929)
        at com.cloud.agent.Agent.processRequest(Agent.java:683)

On the mgmt server side, this is seen:

2024-07-11 16:36:01,674 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-57:ctx-0417fe01 job-2431/job-10081 ctx-0c64ca8a) (logid:81e6bbc0) Invocation exception, caused by: com.cloud.utils.exception.CloudRuntimeException: We cannot stop VM instance {"id":824,"instanceName":"v-824-VM","type":"ConsoleProxy","uuid":"506d0e73-b286-4de6-9df4-46b570eeacd5"} when it is in state Starting
2024-07-11 16:36:01,674 INFO  [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-57:ctx-0417fe01 job-2431/job-10081 ctx-0c64ca8a) (logid:81e6bbc0) Rethrow exception com.cloud.utils.exception.CloudRuntimeException: We cannot stop VM instance {"id":824,"instanceName":"v-824-VM","type":"ConsoleProxy","uuid":"506d0e73-b286-4de6-9df4-46b570eeacd5"} when it is in state Starting
2024-07-11 16:36:01,674 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-57:ctx-0417fe01 job-2431/job-10081) (logid:81e6bbc0) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 824, job origin: 2431
2024-07-11 16:36:01,674 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-57:ctx-0417fe01 job-2431/job-10081) (logid:81e6bbc0) Unable to complete AsyncJobVO: {id:10081, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAADOHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 130014950130305, completeMsid: null, lastUpdated: null, lastPolled: null, created: Thu Jul 11 16:36:01 IST 2024, removed: null}, job origin:2431
com.cloud.utils.exception.CloudRuntimeException: We cannot stop VM instance {"id":824,"instanceName":"v-824-VM","type":"ConsoleProxy","uuid":"506d0e73-b286-4de6-9df4-46b570eeacd5"} when it is in state Starting
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:2107)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:1980)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:5505)
        at jdk.internal.reflect.GeneratedMethodAccessor977.invoke(Unknown Source)

Restarting the agent a couple of times, somehow fixed it. I'm also not sure if it's something to do with my env or with 4.19.1 RC1

Update - in my env, I had a specific IP range (just two IPs) reserved for systemvms, I removed it and relax the systemvm Ip range strictness (reservation) to false; but still same issue.

ISSUE TYPE

• Bug Report

COMPONENT NAME

KVM, SSVM, CPVM, Local storage

CLOUDSTACK VERSION

4.19.1.0 RC1

CONFIGURATION

Adv zone + KVM Ubuntu 22.04

OS / ENVIRONMENT

KVM Ubuntu 22.04

[yadvr]

@sureshanaparti assigned to you to triage, I don't know if it's a blocker or an issue in my env.
cc @shwstppr @vishesh92 @weizhouapache @DaanHoogland @harikrishna-patnala

[yadvr]

Digging further, I found the specific pool it is not able to find is the local storage pool:

root@kvm1:/home/rohit# virsh pool-dumpxml 8aa9768c-cbcf-4e8e-8875-f94a7f9445b6
<pool type='dir'>
  <name>8aa9768c-cbcf-4e8e-8875-f94a7f9445b6</name>
  <uuid>8aa9768c-cbcf-4e8e-8875-f94a7f9445b6</uuid>
  <capacity unit='bytes'>982240026624</capacity>
  <allocation unit='bytes'>198888828928</allocation>
  <available unit='bytes'>783351197696</available>
  <source>
  </source>
  <target>
    <path>/var/lib/libvirt/images</path>
    <permissions>
      <mode>0711</mode>
      <owner>0</owner>
      <group>0</group>
    </permissions>
  </target>
</pool>

In my env, the local storage pool for the same host were removed/added once; it may be possible that somewhere/somehow it's picking an old pool that's removed cc @vishesh92 @sureshanaparti

Or it's not picking the right storage pool (local, the pool ID is the uuid in cloud.storage_pool table) in the host it is trying to deploy the VM on. I think, in the first attempt it somehow tried to ask host1 to use host2's storage pool where it fails; there could be some issue with storage pool mount/using wrt local storage (i.e. not using the right pool ID/UUID for the host where the VM is supposed to start)

[yadvr]

Root cause - this returns true always for local storage - https://github.com/apache/cloudstack/blob/4.19/server/src/main/java/com/cloud/storage/StorageManagerImpl.java#L2795

[sureshanaparti]

Fixed in #9376