apache / cloudstack

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

InsufficientServerCapacityException: Unable to create a deployment for VM instance ..Scope=interface com.cloud.dc.DataCenter; id=1 #6732

Closed bkrajendra closed 1 year ago

bkrajendra commented 1 year ago
ISSUE TYPE
COMPONENT NAME
VR, UI
CLOUDSTACK VERSION
4.17
CONFIGURATION
Basic Netowrking
OS / ENVIRONMENT
Centos 7 Minimal
SUMMARY

System VM are not able to start. I have added NFS as secondary storage. I have also added NFS on primary and its working fine But secondary storage is not detected on the dashboard. NFS is set up on the management server. I have tested the NFS mount manually on the host and it works fine.

STEPS TO REPRODUCE
EXPECTED RESULTS
SystemVMs should start
ACTUAL RESULTS
SystemVMs show starting up and keeps on restarting.

Logs - management server:


inspecting src type TEMPLATE copyAsync inspecting dest type TEMPLATE
2022-09-12 14:20:57,478 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-31:ctx-9a1c5b0a job-2796/job-2828 ctx-b66fed52) (logid:d6e2ec42) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CopyCommand
2022-09-12 14:20:57,511 DEBUG [c.c.a.t.Request] (Work-Job-Executor-31:ctx-9a1c5b0a job-2796/job-2828 ctx-b66fed52) (logid:d6e2ec42) Seq
1-8511240345776816203: Sending  { Cmd
, MgmtId: 95534533553, via: 1(pnqsun), 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.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":"3","format":"QCOW2","accountId":"1","checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.1.27.14/store0/export/secondary","_role":"Image"}},"name":"routing-3","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.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":"3","format":"QCOW2","accountId":"1","checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"fe0641b6-faac-4daf-ba1b-58865dea19ca","name":"pnqsun.local-local-fe0641b6","id":"6","poolType":"Filesystem","host":"10.1.27.11","path":"/var/lib/libvirt/images","port":"0","url":"Filesystem://10.1.27.11/var/lib/libvirt/images/?ROLE=Primary&STOREUUID=fe0641b6-faac-4daf-ba1b-58865dea19ca","isManaged":"false"}},"name":"routing-3","hypervisorType":"KVM","bootable":"false","uniqueName":"routing-3","directDownload":"false","deployAsIs":"false"}},"executeInSequence":"true","options":{},"options2":{},"wait":"10800","bypassHostMaintenance":"false"}}] }
2022-09-12 14:20:57,597 DEBUG [c.c.a.t.Request] (AgentManager-Handler-9:null) (logid:) Seq 1-8511240345776816203: Processing:  { Ans: ,
MgmtId: 95534533553,
via:
1, Ver: v1,
Flags: 110, [{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":"(0 bytes) 0","result":"false","details":"Failed to get volumes from pool: 1a11668e-7526-37ba-bcc9-63965804150c","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 14:20:57,597 DEBUG [c.c.a.m.AgentAttache] (AgentManager-Handler-9:null) (logid:) Seq 1-8511240345776816203: No more commands
found
2022-09-12 14:20:57,598 DEBUG [c.c.a.t.Request] (Work-Job-Executor-31:ctx-9a1c5b0a job-2796/job-2828 ctx-b66fed52) (logid:d6e2ec42) Seq
1-8511240345776816203: Received:  { Ans: , MgmtId: 95534533553, via: 1(pnqsun), Ver: v1, Flags: 110, { PrimaryStorageDownloadAnswer } }
2022-09-12 14:20:57,621 INFO  [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-31:ctx-9a1c5b0a job-2796/job-2828 ctx-b66fed52) (logid:d6e2ec42)
releasing lock for VMTemplateStoragePool 1131
2022-09-12 14:20:57,627 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-31:ctx-9a1c5b0a job-2796/job-2828 ctx-b66fed52) (logid:d6e2ec42) Unable to create
Vol[573|vm=572|ROOT]:Failed to get volumes from pool: 1a11668e-7526-37ba-bcc9-63965804150c
2022-09-12 14:20:57,635 WARN  [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-31:ctx-9a1c5b0a job-2796/job-2828 ctx-b66fed52) (logid:d6e2ec42) Unable to contact
resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:6] is unreachable: Unable to create Vol[573|vm=572|ROOT]:Failed to get
volumes from pool: 1a11668e-7526-37ba-bcc9-63965804150c
        at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1593)
        at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1687)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1179)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5315)
        at jdk.internal.reflect.GeneratedMethodAccessor186.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
        at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5439)
        at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
2022-09-12 14:20:57,665 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-31:ctx-9a1c5b0a job-2796/job-2828 ctx-b66fed52) (logid:d6e2ec42) Cleaning
up resources for
the

releasing lock for VMTemplateStoragePool 1132
2022-09-12 14:20:58,507 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-32:ctx-20a6be64 job-2797/job-2829 ctx-2957d1cc) (logid:35532387) Unable to create Vol[574|vm=573|ROOT]:Failed to get volumes from pool: 1a11668e-7526-37ba-bcc9-63965804150c
2022-09-12 14:20:58,507 WARN  [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-32:ctx-20a6be64 job-2797/job-2829 ctx-2957d1cc) (logid:35532387) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:6] is unreachable: Unable to create Vol[574|vm=573|ROOT]:Failed to get volumes from pool: 1a11668e-7526-37ba-bcc9-63965804150c
        at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1593)
        at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1687)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1179)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5315)
        at jdk.internal.reflect.GeneratedMethodAccessor186.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
        at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5439)
        at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
2022-09-12 14:20:58,523 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-32:ctx-20a6be64 job-2797/job-2829 

Agent Logs:

2022-09-12 19:58:54,848 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:d6e2ec42) Storage pool 1a11668e-7526-37ba-bcc9-63965804150c was successfully removed from libvirt.
2022-09-12 19:58:54,848 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:d6e2ec42) Seq 1-8511240345776816307:  { Ans: , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":"(0 bytes) 0","result":"false","details":"Failed to get volumes from pool: 1a11668e-7526-37ba-bcc9-63965804150c","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 19:58:54,925 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:d6e2ec42) Request:Seq 1-8511240345776816308:  { Cmd , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","controlIp":"169.254.218.216","forceStop":"false","volumesToDisconnect":[],"vmName":"s-588-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 19:58:54,926 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:d6e2ec42) Processing command: com.cloud.agent.api.StopCommand
2022-09-12 19:58:54,926 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-5:null) (logid:d6e2ec42) backing up the cmdline
2022-09-12 19:58:56,550 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:35532387) Request:Seq 1-8511240345776816309:  { Cmd , MgmtId: 95534533553, via: 1, 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.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":"3","format":"QCOW2","accountId":"1","checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.1.27.14/store0/export/secondary","_role":"Image"}},"name":"routing-3","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.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":"3","format":"QCOW2","accountId":"1","checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"fe0641b6-faac-4daf-ba1b-58865dea19ca","name":"pnqsun.local-local-fe0641b6","id":"6","poolType":"Filesystem","host":"10.1.27.11","path":"/var/lib/libvirt/images","port":"0","url":"Filesystem://10.1.27.11/var/lib/libvirt/images/?ROLE=Primary&STOREUUID=fe0641b6-faac-4daf-ba1b-58865dea19ca","isManaged":"false"}},"name":"routing-3","hypervisorType":"KVM","bootable":"false","uniqueName":"routing-3","directDownload":"false","deployAsIs":"false"}},"executeInSequence":"true","options":{},"options2":{},"wait":"10800","bypassHostMaintenance":"false"}}] }
2022-09-12 19:58:56,550 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:35532387) Processing command: org.apache.cloudstack.storage.command.CopyCommand
2022-09-12 19:58:56,550 DEBUG [storage.resource.StorageSubsystemCommandHandlerBase] (agentRequest-Handler-1:null) (logid:35532387) Executing command CopyCommand: [{"srcTO":{"path":"template/tmpl/1/3/","origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":3,"format":"QCOW2","accountId":1,"checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"_url":"nfs://10.1.27.14/store0/export/secondary","_role":"Image"},"name":"routing-3","hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"destTO":{"origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":3,"format":"QCOW2","accountId":1,"checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"uuid":"fe0641b6-faac-4daf-ba1b-58865dea19ca","name":"pnqsun.local-local-fe0641b6","id":6,"poolType":"Filesystem","host":"10.1.27.11","path":"/var/lib/libvirt/images","port":0,"url":"Filesystem://10.1.27.11/var/lib/libvirt/images/?ROLE\u003dPrimary\u0026STOREUUID\u003dfe0641b6-faac-4daf-ba1b-58865dea19ca","isManaged":false},"name":"routing-3","hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"executeInSequence":true,"options":{},"options2":{},"contextMap":{"logid":"35532387","job":"job-2797/job-2877"},"wait":10800,"bypassHostMaintenance":false}].
2022-09-12 19:58:56,550 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Attempting to create storage pool 1a11668e-7526-37ba-bcc9-63965804150c (NetworkFilesystem) in libvirt
2022-09-12 19:58:56,550 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:35532387) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:58:56,550 WARN  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Storage pool 1a11668e-7526-37ba-bcc9-63965804150c was not found running in libvirt. Need to create it.
2022-09-12 19:58:56,550 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Didn't find an existing storage pool 1a11668e-7526-37ba-bcc9-63965804150c by UUID, checking for pools with duplicate paths
2022-09-12 19:58:56,551 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Checking path of existing pool hdd-data against pool we want to create
2022-09-12 19:58:56,551 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Checking path of existing pool fe0641b6-faac-4daf-ba1b-58865dea19ca against pool we want to create
2022-09-12 19:58:56,552 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Checking path of existing pool 077e9266-fecc-3171-8b1f-6c634ead9ca3 against pool we want to create
2022-09-12 19:58:56,553 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Checking path of existing pool root against pool we want to create
2022-09-12 19:58:56,553 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Checking path of existing pool sdd0 against pool we want to create
2022-09-12 19:58:56,554 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Attempting to create storage pool 1a11668e-7526-37ba-bcc9-63965804150c
2022-09-12 19:58:56,554 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) <pool type='netfs'>
<name>1a11668e-7526-37ba-bcc9-63965804150c</name>
<uuid>1a11668e-7526-37ba-bcc9-63965804150c</uuid>
<source>
<host name='10.1.27.14'/>
<dir path='/store0/export/secondary/template/tmpl/1/3'/>
</source>
<target>
<path>/mnt/1a11668e-7526-37ba-bcc9-63965804150c</path>
</target>
</pool>

2022-09-12 19:58:56,555 DEBUG [utils.script.Script] (agentRequest-Handler-1:null) (logid:35532387) Executing: /bin/bash -c mountpoint -q /mnt/1a11668e-7526-37ba-bcc9-63965804150c
2022-09-12 19:58:56,555 DEBUG [utils.script.Script] (agentRequest-Handler-1:null) (logid:35532387) Executing while with timeout : 3600000
2022-09-12 19:58:56,557 DEBUG [utils.script.Script] (agentRequest-Handler-1:null) (logid:35532387) Exit value is 1
2022-09-12 19:58:56,557 DEBUG [utils.script.Script] (agentRequest-Handler-1:null) (logid:35532387) 1
2022-09-12 19:58:56,595 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Trying to fetch storage pool 1a11668e-7526-37ba-bcc9-63965804150c from libvirt
2022-09-12 19:58:56,595 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:35532387) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:58:56,597 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Successfully refreshed pool 1a11668e-7526-37ba-bcc9-63965804150c
Capacity: (196.67 GB) 211176128512 Used: (128.00 KB) 131072 Available: (196.67 GB) 211175997440
2022-09-12 19:58:56,599 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Attempting to remove storage pool 1a11668e-7526-37ba-bcc9-63965804150c from libvirt
2022-09-12 19:58:56,599 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:35532387) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:58:56,600 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Storage pool 1a11668e-7526-37ba-bcc9-63965804150c has no corresponding secret. Not removing any secret.
2022-09-12 19:58:56,622 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Storage pool 1a11668e-7526-37ba-bcc9-63965804150c was successfully removed from libvirt.
2022-09-12 19:58:56,624 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:35532387) Seq 1-8511240345776816309:  { Ans: , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":"(0 bytes) 0","result":"false","details":"Failed to get volumes from pool: 1a11668e-7526-37ba-bcc9-63965804150c","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 19:58:56,689 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:35532387) Request:Seq 1-8511240345776816310:  { Cmd , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","controlIp":"169.254.1.187","forceStop":"false","volumesToDisconnect":[],"vmName":"v-589-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 19:58:56,689 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:35532387) Processing command: com.cloud.agent.api.StopCommand
2022-09-12 19:58:56,689 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-3:null) (logid:35532387) backing up the cmdline
2022-09-12 19:58:57,933 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-5:null) (logid:d6e2ec42) Failed to backup cmdline file due to There was a problem while connecting to 169.254.218.216:3922
2022-09-12 19:58:57,933 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:d6e2ec42) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:58:57,933 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:d6e2ec42) Can not find KVM connection for Instance: s-588-VM, continuing.
2022-09-12 19:58:57,933 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:d6e2ec42) Looking for libvirtd connection at: lxc:///
2022-09-12 19:58:57,933 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:d6e2ec42) Can not find LXC connection for Instance: s-588-VM, continuing.
2022-09-12 19:58:57,933 WARN  [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:d6e2ec42) Can not find a connection for Instance s-588-VM. Assuming the default connection.
2022-09-12 19:58:57,933 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:d6e2ec42) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:58:57,934 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:d6e2ec42) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 's-588-VM'
2022-09-12 19:58:57,934 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:d6e2ec42) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 's-588-VM'
2022-09-12 19:58:57,934 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:d6e2ec42) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 's-588-VM'
2022-09-12 19:58:57,934 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:d6e2ec42) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname s-588-VM
2022-09-12 19:58:57,935 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:d6e2ec42) Executing while with timeout : 1800000
2022-09-12 19:58:58,007 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:d6e2ec42) Execution is successful.
2022-09-12 19:58:58,007 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:d6e2ec42) Failed to get vm :Domain not found: no domain with matching name 's-588-VM'
2022-09-12 19:58:58,007 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:d6e2ec42) Try to stop the vm at first
2022-09-12 19:58:58,008 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:d6e2ec42) VM s-588-VM doesn't exist, no need to stop it
2022-09-12 19:58:58,008 WARN  [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-5:null) (logid:d6e2ec42) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied.
2022-09-12 19:58:58,008 WARN  [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-5:null) (logid:d6e2ec42) Groovy scripting engine is not initialized. Data transformation skipped.
2022-09-12 19:58:58,008 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:d6e2ec42) Seq 1-8511240345776816308:  { Ans: , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 19:58:59,697 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-3:null) (logid:35532387) Failed to backup cmdline file due to There was a problem while connecting to 169.254.1.187:3922
2022-09-12 19:58:59,697 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:35532387) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:58:59,697 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:35532387) Can not find KVM connection for Instance: v-589-VM, continuing.
2022-09-12 19:58:59,697 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:35532387) Looking for libvirtd connection at: lxc:///
2022-09-12 19:58:59,697 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:35532387) Can not find LXC connection for Instance: v-589-VM, continuing.
2022-09-12 19:58:59,697 WARN  [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:35532387) Can not find a connection for Instance v-589-VM. Assuming the default connection.
2022-09-12 19:58:59,697 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:35532387) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:58:59,698 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:35532387) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'v-589-VM'
2022-09-12 19:58:59,698 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:35532387) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'v-589-VM'
2022-09-12 19:58:59,698 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:35532387) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'v-589-VM'
2022-09-12 19:58:59,698 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:35532387) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname v-589-VM
2022-09-12 19:58:59,699 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:35532387) Executing while with timeout : 1800000
2022-09-12 19:58:59,773 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:35532387) Execution is successful.
2022-09-12 19:58:59,773 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:35532387) Failed to get vm :Domain not found: no domain with matching name 'v-589-VM'
2022-09-12 19:58:59,773 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:35532387) Try to stop the vm at first
2022-09-12 19:58:59,773 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:35532387) VM v-589-VM doesn't exist, no need to stop it
2022-09-12 19:58:59,773 WARN  [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-3:null) (logid:35532387) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied.
2022-09-12 19:58:59,773 WARN  [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-3:null) (logid:35532387) Groovy scripting engine is not initialized. Data transformation skipped.
2022-09-12 19:58:59,774 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:35532387) Seq 1-8511240345776816310:  { Ans: , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 19:59:19,930 DEBUG [kvm.resource.LibvirtConnection] (Thread-1:null) (logid:) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:59:19,931 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) (logid:) Found NFS storage pool [077e9266-fecc-3171-8b1f-6c634ead9ca3] in libvirt, continuing.
2022-09-12 19:59:19,931 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) (logid:) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 10.1.27.14 -p /store0/export/primary -m /mnt/077e9266-fecc-3171-8b1f-6c634ead9ca3 -h 10.1.27.11
2022-09-12 19:59:19,932 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) (logid:) Executing while with timeout : 60000
2022-09-12 19:59:19,943 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) (logid:) Execution is successful.
2022-09-12 19:59:19,943 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1:null) (logid:) The command (/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 10.1.27.14 -p /store0/export/primary -m /mnt/077e9266-fecc-3171-8b1f-6c634ead9ca3 -h 10.1.27.11 ), to the pool [077e9266-fecc-3171-8b1f-6c634ead9ca3], has the result [null].
2022-09-12 19:59:24,792 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:d6e2ec42) Request:Seq 1-8511240345776816311:  { Cmd , MgmtId: 95534533553, via: 1, 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.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":"3","format":"QCOW2","accountId":"1","checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.1.27.14/store0/export/secondary","_role":"Image"}},"name":"routing-3","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.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":"3","format":"QCOW2","accountId":"1","checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"fe0641b6-faac-4daf-ba1b-58865dea19ca","name":"pnqsun.local-local-fe0641b6","id":"6","poolType":"Filesystem","host":"10.1.27.11","path":"/var/lib/libvirt/images","port":"0","url":"Filesystem://10.1.27.11/var/lib/libvirt/images/?ROLE=Primary&STOREUUID=fe0641b6-faac-4daf-ba1b-58865dea19ca","isManaged":"false"}},"name":"routing-3","hypervisorType":"KVM","bootable":"false","uniqueName":"routing-3","directDownload":"false","deployAsIs":"false"}},"executeInSequence":"true","options":{},"options2":{},"wait":"10800","bypassHostMaintenance":"false"}}] }
2022-09-12 19:59:24,792 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:d6e2ec42) Processing command: org.apache.cloudstack.storage.command.CopyCommand
2022-09-12 19:59:24,792 DEBUG [storage.resource.StorageSubsystemCommandHandlerBase] (agentRequest-Handler-4:null) (logid:d6e2ec42) Executing command CopyCommand: [{"srcTO":{"path":"template/tmpl/1/3/","origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":3,"format":"QCOW2","accountId":1,"checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"_url":"nfs://10.1.27.14/store0/export/secondary","_role":"Image"},"name":"routing-3","hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"destTO":{"origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":3,"format":"QCOW2","accountId":1,"checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"uuid":"fe0641b6-faac-4daf-ba1b-58865dea19ca","name":"pnqsun.local-local-fe0641b6","id":6,"poolType":"Filesystem","host":"10.1.27.11","path":"/var/lib/libvirt/images","port":0,"url":"Filesystem://10.1.27.11/var/lib/libvirt/images/?ROLE\u003dPrimary\u0026STOREUUID\u003dfe0641b6-faac-4daf-ba1b-58865dea19ca","isManaged":false},"name":"routing-3","hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"executeInSequence":true,"options":{},"options2":{},"contextMap":{"logid":"d6e2ec42","job":"job-2796/job-2878"},"wait":10800,"bypassHostMaintenance":false}].
2022-09-12 19:59:24,792 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Attempting to create storage pool 1a11668e-7526-37ba-bcc9-63965804150c (NetworkFilesystem) in libvirt
2022-09-12 19:59:24,792 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-4:null) (logid:d6e2ec42) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:59:24,793 WARN  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Storage pool 1a11668e-7526-37ba-bcc9-63965804150c was not found running in libvirt. Need to create it.
2022-09-12 19:59:24,793 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Didn't find an existing storage pool 1a11668e-7526-37ba-bcc9-63965804150c by UUID, checking for pools with duplicate paths
2022-09-12 19:59:24,793 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Checking path of existing pool hdd-data against pool we want to create
2022-09-12 19:59:24,795 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Checking path of existing pool fe0641b6-faac-4daf-ba1b-58865dea19ca against pool we want to create
2022-09-12 19:59:24,795 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Checking path of existing pool 077e9266-fecc-3171-8b1f-6c634ead9ca3 against pool we want to create
2022-09-12 19:59:24,796 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Checking path of existing pool root against pool we want to create
2022-09-12 19:59:24,797 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Checking path of existing pool sdd0 against pool we want to create
2022-09-12 19:59:24,798 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Attempting to create storage pool 1a11668e-7526-37ba-bcc9-63965804150c
2022-09-12 19:59:24,798 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) <pool type='netfs'>
<name>1a11668e-7526-37ba-bcc9-63965804150c</name>
<uuid>1a11668e-7526-37ba-bcc9-63965804150c</uuid>
<source>
<host name='10.1.27.14'/>
<dir path='/store0/export/secondary/template/tmpl/1/3'/>
</source>
<target>
<path>/mnt/1a11668e-7526-37ba-bcc9-63965804150c</path>
</target>
</pool>

2022-09-12 19:59:24,798 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:d6e2ec42) Executing: /bin/bash -c mountpoint -q /mnt/1a11668e-7526-37ba-bcc9-63965804150c
2022-09-12 19:59:24,799 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:d6e2ec42) Executing while with timeout : 3600000
2022-09-12 19:59:24,800 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:d6e2ec42) Exit value is 1
2022-09-12 19:59:24,800 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:d6e2ec42) 1
2022-09-12 19:59:24,842 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Trying to fetch storage pool 1a11668e-7526-37ba-bcc9-63965804150c from libvirt
2022-09-12 19:59:24,842 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-4:null) (logid:d6e2ec42) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:59:24,843 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Successfully refreshed pool 1a11668e-7526-37ba-bcc9-63965804150c
Capacity: (196.67 GB) 211176128512 Used: (128.00 KB) 131072 Available: (196.67 GB) 211175997440
2022-09-12 19:59:24,846 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Attempting to remove storage pool 1a11668e-7526-37ba-bcc9-63965804150c from libvirt
2022-09-12 19:59:24,846 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-4:null) (logid:d6e2ec42) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:59:24,847 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Storage pool 1a11668e-7526-37ba-bcc9-63965804150c has no corresponding secret. Not removing any secret.
2022-09-12 19:59:24,872 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:d6e2ec42) Storage pool 1a11668e-7526-37ba-bcc9-63965804150c was successfully removed from libvirt.
2022-09-12 19:59:24,872 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:d6e2ec42) Seq 1-8511240345776816311:  { Ans: , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":"(0 bytes) 0","result":"false","details":"Failed to get volumes from pool: 1a11668e-7526-37ba-bcc9-63965804150c","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 19:59:24,955 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:d6e2ec42) Request:Seq 1-8511240345776816312:  { Cmd , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","controlIp":"169.254.68.118","forceStop":"false","volumesToDisconnect":[],"vmName":"s-588-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 19:59:24,955 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:d6e2ec42) Processing command: com.cloud.agent.api.StopCommand
2022-09-12 19:59:24,955 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-2:null) (logid:d6e2ec42) backing up the cmdline
2022-09-12 19:59:26,539 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:35532387) Request:Seq 1-8511240345776816313:  { Cmd , MgmtId: 95534533553, via: 1, 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.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":"3","format":"QCOW2","accountId":"1","checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.1.27.14/store0/export/secondary","_role":"Image"}},"name":"routing-3","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.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":"3","format":"QCOW2","accountId":"1","checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":"false","displayText":"SystemVM Template (KVM)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"fe0641b6-faac-4daf-ba1b-58865dea19ca","name":"pnqsun.local-local-fe0641b6","id":"6","poolType":"Filesystem","host":"10.1.27.11","path":"/var/lib/libvirt/images","port":"0","url":"Filesystem://10.1.27.11/var/lib/libvirt/images/?ROLE=Primary&STOREUUID=fe0641b6-faac-4daf-ba1b-58865dea19ca","isManaged":"false"}},"name":"routing-3","hypervisorType":"KVM","bootable":"false","uniqueName":"routing-3","directDownload":"false","deployAsIs":"false"}},"executeInSequence":"true","options":{},"options2":{},"wait":"10800","bypassHostMaintenance":"false"}}] }
2022-09-12 19:59:26,539 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:35532387) Processing command: org.apache.cloudstack.storage.command.CopyCommand
2022-09-12 19:59:26,539 DEBUG [storage.resource.StorageSubsystemCommandHandlerBase] (agentRequest-Handler-1:null) (logid:35532387) Executing command CopyCommand: [{"srcTO":{"path":"template/tmpl/1/3/","origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":3,"format":"QCOW2","accountId":1,"checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"_url":"nfs://10.1.27.14/store0/export/secondary","_role":"Image"},"name":"routing-3","hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"destTO":{"origUrl":"https://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.0-kvm.qcow2.bz2","uuid":"4b5647e4-2e67-11ed-b09d-00163e4d4bb1","id":3,"format":"QCOW2","accountId":1,"checksum":"48fe26b04fd8db7099d0b9674ef2d9ba","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"uuid":"fe0641b6-faac-4daf-ba1b-58865dea19ca","name":"pnqsun.local-local-fe0641b6","id":6,"poolType":"Filesystem","host":"10.1.27.11","path":"/var/lib/libvirt/images","port":0,"url":"Filesystem://10.1.27.11/var/lib/libvirt/images/?ROLE\u003dPrimary\u0026STOREUUID\u003dfe0641b6-faac-4daf-ba1b-58865dea19ca","isManaged":false},"name":"routing-3","hypervisorType":"KVM","bootable":false,"uniqueName":"routing-3","directDownload":false,"deployAsIs":false},"executeInSequence":true,"options":{},"options2":{},"contextMap":{"logid":"35532387","job":"job-2797/job-2879"},"wait":10800,"bypassHostMaintenance":false}].
2022-09-12 19:59:26,539 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Attempting to create storage pool 1a11668e-7526-37ba-bcc9-63965804150c (NetworkFilesystem) in libvirt
2022-09-12 19:59:26,539 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:35532387) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:59:26,540 WARN  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Storage pool 1a11668e-7526-37ba-bcc9-63965804150c was not found running in libvirt. Need to create it.
2022-09-12 19:59:26,540 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Didn't find an existing storage pool 1a11668e-7526-37ba-bcc9-63965804150c by UUID, checking for pools with duplicate paths
2022-09-12 19:59:26,540 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Checking path of existing pool hdd-data against pool we want to create
2022-09-12 19:59:26,541 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Checking path of existing pool fe0641b6-faac-4daf-ba1b-58865dea19ca against pool we want to create
2022-09-12 19:59:26,541 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Checking path of existing pool 077e9266-fecc-3171-8b1f-6c634ead9ca3 against pool we want to create
2022-09-12 19:59:26,542 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Checking path of existing pool root against pool we want to create
2022-09-12 19:59:26,543 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Checking path of existing pool sdd0 against pool we want to create
2022-09-12 19:59:26,544 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Attempting to create storage pool 1a11668e-7526-37ba-bcc9-63965804150c
2022-09-12 19:59:26,544 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) <pool type='netfs'>
<name>1a11668e-7526-37ba-bcc9-63965804150c</name>
<uuid>1a11668e-7526-37ba-bcc9-63965804150c</uuid>
<source>
<host name='10.1.27.14'/>
<dir path='/store0/export/secondary/template/tmpl/1/3'/>
</source>
<target>
<path>/mnt/1a11668e-7526-37ba-bcc9-63965804150c</path>
</target>
</pool>

2022-09-12 19:59:26,544 DEBUG [utils.script.Script] (agentRequest-Handler-1:null) (logid:35532387) Executing: /bin/bash -c mountpoint -q /mnt/1a11668e-7526-37ba-bcc9-63965804150c
2022-09-12 19:59:26,545 DEBUG [utils.script.Script] (agentRequest-Handler-1:null) (logid:35532387) Executing while with timeout : 3600000
2022-09-12 19:59:26,547 DEBUG [utils.script.Script] (agentRequest-Handler-1:null) (logid:35532387) Exit value is 1
2022-09-12 19:59:26,547 DEBUG [utils.script.Script] (agentRequest-Handler-1:null) (logid:35532387) 1
2022-09-12 19:59:26,589 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Trying to fetch storage pool 1a11668e-7526-37ba-bcc9-63965804150c from libvirt
2022-09-12 19:59:26,589 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:35532387) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:59:26,590 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Successfully refreshed pool 1a11668e-7526-37ba-bcc9-63965804150c
Capacity: (196.67 GB) 211176128512 Used: (128.00 KB) 131072 Available: (196.67 GB) 211175997440
2022-09-12 19:59:26,593 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Attempting to remove storage pool 1a11668e-7526-37ba-bcc9-63965804150c from libvirt
2022-09-12 19:59:26,593 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:35532387) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:59:26,593 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Storage pool 1a11668e-7526-37ba-bcc9-63965804150c has no corresponding secret. Not removing any secret.
2022-09-12 19:59:26,616 INFO  [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:35532387) Storage pool 1a11668e-7526-37ba-bcc9-63965804150c was successfully removed from libvirt.
2022-09-12 19:59:26,616 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:35532387) Seq 1-8511240345776816313:  { Ans: , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":"(0 bytes) 0","result":"false","details":"Failed to get volumes from pool: 1a11668e-7526-37ba-bcc9-63965804150c","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 19:59:26,687 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:35532387) Request:Seq 1-8511240345776816314:  { Cmd , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","controlIp":"169.254.198.86","forceStop":"false","volumesToDisconnect":[],"vmName":"v-589-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 19:59:26,687 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:35532387) Processing command: com.cloud.agent.api.StopCommand
2022-09-12 19:59:26,687 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-5:null) (logid:35532387) backing up the cmdline
2022-09-12 19:59:27,961 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-2:null) (logid:d6e2ec42) Failed to backup cmdline file due to There was a problem while connecting to 169.254.68.118:3922
2022-09-12 19:59:27,961 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:d6e2ec42) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:59:27,961 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:d6e2ec42) Can not find KVM connection for Instance: s-588-VM, continuing.
2022-09-12 19:59:27,961 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:d6e2ec42) Looking for libvirtd connection at: lxc:///
2022-09-12 19:59:27,961 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:d6e2ec42) Can not find LXC connection for Instance: s-588-VM, continuing.
2022-09-12 19:59:27,961 WARN  [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:d6e2ec42) Can not find a connection for Instance s-588-VM. Assuming the default connection.
2022-09-12 19:59:27,961 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:d6e2ec42) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:59:27,962 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:d6e2ec42) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 's-588-VM'
2022-09-12 19:59:27,962 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:d6e2ec42) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 's-588-VM'
2022-09-12 19:59:27,962 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:d6e2ec42) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 's-588-VM'
2022-09-12 19:59:27,962 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:d6e2ec42) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname s-588-VM
2022-09-12 19:59:27,962 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:d6e2ec42) Executing while with timeout : 1800000
2022-09-12 19:59:28,036 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:d6e2ec42) Execution is successful.
2022-09-12 19:59:28,037 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:d6e2ec42) Failed to get vm :Domain not found: no domain with matching name 's-588-VM'
2022-09-12 19:59:28,037 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:d6e2ec42) Try to stop the vm at first
2022-09-12 19:59:28,037 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:d6e2ec42) VM s-588-VM doesn't exist, no need to stop it
2022-09-12 19:59:28,037 WARN  [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-2:null) (logid:d6e2ec42) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied.
2022-09-12 19:59:28,037 WARN  [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-2:null) (logid:d6e2ec42) Groovy scripting engine is not initialized. Data transformation skipped.
2022-09-12 19:59:28,037 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:d6e2ec42) Seq 1-8511240345776816312:  { Ans: , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2022-09-12 19:59:29,693 DEBUG [resource.wrapper.LibvirtStopCommandWrapper] (agentRequest-Handler-5:null) (logid:35532387) Failed to backup cmdline file due to There was a problem while connecting to 169.254.198.86:3922
2022-09-12 19:59:29,693 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:35532387) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:59:29,693 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:35532387) Can not find KVM connection for Instance: v-589-VM, continuing.
2022-09-12 19:59:29,693 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:35532387) Looking for libvirtd connection at: lxc:///
2022-09-12 19:59:29,693 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:35532387) Can not find LXC connection for Instance: v-589-VM, continuing.
2022-09-12 19:59:29,693 WARN  [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:35532387) Can not find a connection for Instance v-589-VM. Assuming the default connection.
2022-09-12 19:59:29,693 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:35532387) Looking for libvirtd connection at: qemu:///system
2022-09-12 19:59:29,694 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:35532387) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'v-589-VM'
2022-09-12 19:59:29,694 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:35532387) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'v-589-VM'
2022-09-12 19:59:29,694 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:35532387) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'v-589-VM'
2022-09-12 19:59:29,694 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:35532387) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname v-589-VM
2022-09-12 19:59:29,695 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:35532387) Executing while with timeout : 1800000
2022-09-12 19:59:29,766 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:35532387) Execution is successful.
2022-09-12 19:59:29,767 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:35532387) Failed to get vm :Domain not found: no domain with matching name 'v-589-VM'
2022-09-12 19:59:29,767 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:35532387) Try to stop the vm at first
2022-09-12 19:59:29,767 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:35532387) VM v-589-VM doesn't exist, no need to stop it
2022-09-12 19:59:29,767 WARN  [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-5:null) (logid:35532387) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied.
2022-09-12 19:59:29,767 WARN  [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-5:null) (logid:35532387) Groovy scripting engine is not initialized. Data transformation skipped.
2022-09-12 19:59:29,768 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:35532387) Seq 1-8511240345776816314:  { Ans: , MgmtId: 95534533553, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }

Storage pools:

🐱 > list storagepools
{
  "count": 4,
  "storagepool": [
    {
      "clusterid": "d2a5c86b-dec5-4e57-9b1f-8237d14f2a78",
      "clustername": "Cluster 1",
      "created": "2022-09-12T04:32:47+0000",
      "disksizeallocated": 0,
      "disksizetotal": 211176128512,
      "disksizeused": 131072,
      "hasannotations": false,
      "hypervisor": "KVM",
      "id": "077e9266-fecc-3171-8b1f-6c634ead9ca3",
      "ipaddress": "10.1.27.14",
      "name": "primary_nfs",
      "overprovisionfactor": "2.0",
      "path": "/store0/export/primary",
      "podid": "448acbd9-e767-4f08-96d5-567b4c60424e",
      "podname": "Pod1-The Rack",
      "provider": "DefaultPrimary",
      "scope": "CLUSTER",
      "state": "Up",
      "storagecapabilities": {
        "VOLUME_SNAPSHOT_QUIESCEVM": "false"
      },
      "type": "NetworkFilesystem",
      "zoneid": "9c1bc99b-a6f4-45d2-9b7e-029b260e042f",
      "zonename": "Pune"
    },
    {
      "clusterid": "d2a5c86b-dec5-4e57-9b1f-8237d14f2a78",
      "clustername": "Cluster 1",
      "created": "2022-09-10T14:15:42+0000",
      "disksizeallocated": 0,
      "disksizetotal": 64393052160,
      "disksizeused": 14333464576,
      "hasannotations": false,
      "hypervisor": "KVM",
      "id": "fe0641b6-faac-4daf-ba1b-58865dea19ca",
      "ipaddress": "10.1.27.11",
      "name": "pnqsun.local-local-fe0641b6",
      "overprovisionfactor": "2.0",
      "path": "/var/lib/libvirt/images",
      "podid": "448acbd9-e767-4f08-96d5-567b4c60424e",
      "podname": "Pod1-The Rack",
      "provider": "DefaultPrimary",
      "scope": "HOST",
      "state": "Up",
      "storagecapabilities": {
        "VOLUME_SNAPSHOT_QUIESCEVM": "false"
      },
      "type": "Filesystem",
      "zoneid": "9c1bc99b-a6f4-45d2-9b7e-029b260e042f",
      "zonename": "Pune"
    },
    {
      "clusterid": "d2a5c86b-dec5-4e57-9b1f-8237d14f2a78",
      "clustername": "Cluster 1",
      "created": "2022-09-10T13:04:22+0000",
      "disksizeallocated": 0,
      "disksizetotal": 4690095898624,
      "disksizeused": 0,
      "hasannotations": false,
      "hypervisor": "KVM",
      "id": "9003816b-c28b-4e53-ac9c-d3ebdd6a5e2b",
      "ipaddress": "localhost",
      "name": "HDD",
      "overprovisionfactor": "2.0",
      "path": "/hdd-data",
      "podid": "448acbd9-e767-4f08-96d5-567b4c60424e",
      "podname": "Pod1-The Rack",
      "provider": "DefaultPrimary",
      "scope": "CLUSTER",
      "state": "Up",
      "storagecapabilities": {
        "VOLUME_SNAPSHOT_QUIESCEVM": "false"
      },
      "tags": "HDD",
      "type": "CLVM",
      "zoneid": "9c1bc99b-a6f4-45d2-9b7e-029b260e042f",
      "zonename": "Pune"
    },
    {
      "clusterid": "d2a5c86b-dec5-4e57-9b1f-8237d14f2a78",
      "clustername": "Cluster 1",
      "created": "2022-09-09T13:30:57+0000",
      "disksizeallocated": 0,
      "disksizetotal": 959652560896,
      "disksizeused": 0,
      "hasannotations": false,
      "hypervisor": "KVM",
      "id": "b17ab547-0fcf-45e2-ae4a-080068d4d8a6",
      "ipaddress": "localhost",
      "name": "SDD",
      "overprovisionfactor": "2.0",
      "path": "/sdd0",
      "podid": "448acbd9-e767-4f08-96d5-567b4c60424e",
      "podname": "Pod1-The Rack",
      "provider": "DefaultPrimary",
      "scope": "CLUSTER",
      "state": "Up",
      "storagecapabilities": {
        "VOLUME_SNAPSHOT_QUIESCEVM": "false"
      },
      "tags": "SDD",
      "type": "CLVM",
      "zoneid": "9c1bc99b-a6f4-45d2-9b7e-029b260e042f",
      "zonename": "Pune"
    }
  ]
}

image

image

image

DaanHoogland commented 1 year ago

@bkrajendra , can you mount the storages on your hypervisor?

bkrajendra commented 1 year ago

@DaanHoogland Yes, as I said I created a test mount on the hypervisor host and I am able to do it. Even primary storage is visible in the storage pool, but not sure why secondary storage is not coming on the storage pool list.

bkrajendra commented 1 year ago

secondary storage shows in the mount on the management server.

10.1.27.14:/store0/export/secondary on /var/lib/cloudstack/mnt/95534533553.4e443153 type nfs4 (rw,relatime,vers=4.2,rsize=131072,wsize=131072,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,clientaddr=10.1.27.14,local_lock=none,addr=10.1.27.14)

my nfs server is on the management server. still I am getting InsufficientServerCapacityException: Unable to create a deployment for VM instance Its destroying and creating VMs... currently showing [v-2221-VM]

I have tried with true and false values to Enable local storage for user VMs

What's wrong here?

bkrajendra commented 1 year ago

list capacity shows:

🐱 > list capacity 
{
      "capacitytotal": 0,
      "capacityused": 0,
      "name": "SECONDARY_STORAGE",
      "percentused": "0",
      "type": 6,
      "zoneid": "9c1bc99b-a6f4-45d2-9b7e-029b260e042f",
      "zonename": "Pune"
    }
DaanHoogland commented 1 year ago

so you can mount the export on the local machine i.e. the management server, and on the hypervisor host. but the secondary storage VM does not come up. the VM with a name like s-###-VM (not v-###-VM). I suppose you did but just for completeness, did you check your network configuration, any routers between the two machines. Can you show the export line for the NFS share? You did seed the secondary storage with the built-in templates and they ended up on the secstor?

bkrajendra commented 1 year ago

@DaanHoogland There is a Router between two machines. Management server+NFS is on a different host inside VM. but in the same subnet. Export line of nfs share:

/store0/export/secondary *(rw,async,no_root_squash,no_subtree_check)
/store0/export/primary *(rw,async,no_root_squash,no_subtree_check)

I used UI to download the template. I registered it through UI and it got downloaded after I create secondary storage. I can see the template folder created inside the secondary store export.

Issue is SystemVMs are not getting started. It comes on UI, shows starting and then gets removed, and again new gets created. Getting error continuously on console ```InsufficientServerCapacityException````

DaanHoogland commented 1 year ago

@bkrajendra , unfortunately InsufficientServerCapacityException is a very generic error. Are there any more log messages for job-2796or ctx-b66fed52 before what you shared? I can not tell the issue from what i see. But i'm sure it is some environmental thing, we run dozens of automated installs of main and 4.17 for test puroses.

bkrajendra commented 1 year ago

@DaanHoogland I deleted systemvm template and tried to seed them manually on the management server with:

 /usr/share/cloudstack-common/scripts/storage/secondary/cloud-install-sys-tmplt -m /store0/export/secondary -u http://download.cloudstack.org/systemvm/4.17/systemvmtemplate-4.17.0-kvm.qcow2.bz2 -h kvm -F 

While doing this I discovered there is no space left in the management server / (root). hence it was not able to download it.

For a workaround, I created a soft link on another drive (/store0 = 200GB) and worked. Now my SystemVMs are up. Its secondary storage VM shows in an alert state. Still, secondary storage shows 0/0. Could this be due to the Management Server root drive being full?

bkrajendra commented 1 year ago

find the diagnostic logs on systemVMs: console proxy VM

root@v-2995-VM:~# /usr/local/cloud/systemvm/ssvm-check.sh
================================================
First DNS server is  8.8.8.8
PING 8.8.8.8 (8.8.8.8): 56 data bytes
64 bytes from 8.8.8.8: icmp_seq=0 ttl=118 time=7.841 ms
64 bytes from 8.8.8.8: icmp_seq=1 ttl=118 time=5.882 ms
--- 8.8.8.8 ping statistics ---
2 packets transmitted, 2 packets received, 0% packet loss
round-trip min/avg/max/stddev = 5.882/6.861/7.841/0.980 ms
Good: Can ping DNS server
================================================
Good: DNS resolves cloudstack.apache.org
================================================
ERROR: NFS is not currently mounted
Try manually mounting from inside the VM
NFS server is  10.1.27.235
PING 10.1.27.235 (10.1.27.235): 56 data bytes
64 bytes from 10.1.27.235: icmp_seq=0 ttl=64 time=0.045 ms
64 bytes from 10.1.27.235: icmp_seq=1 ttl=64 time=0.026 ms
--- 10.1.27.235 ping statistics ---
2 packets transmitted, 2 packets received, 0% packet loss
round-trip min/avg/max/stddev = 0.026/0.035/0.045/0.000 ms
Good: Can ping nfs server
================================================
Management server is 10.1.27.14. Checking connectivity.
Good: Can connect to management server 10.1.27.14 port 8250
================================================
Good: Java process is running
================================================
Tests Complete. Look for ERROR or WARNING above.

Secondary storage VM

root@s-2994-VM:~# /usr/local/cloud/systemvm/ssvm-check.sh
================================================
First DNS server is  8.8.8.8
PING 8.8.8.8 (8.8.8.8): 56 data bytes
64 bytes from 8.8.8.8: icmp_seq=0 ttl=118 time=9.404 ms
64 bytes from 8.8.8.8: icmp_seq=1 ttl=118 time=5.752 ms
--- 8.8.8.8 ping statistics ---
2 packets transmitted, 2 packets received, 0% packet loss
round-trip min/avg/max/stddev = 5.752/7.578/9.404/1.826 ms
Good: Can ping DNS server
================================================
Good: DNS resolves cloudstack.apache.org
================================================
nfs is currently mounted
Mount point is /mnt/SecStorage/660f6cc7-82c6-336f-91f9-b2ce91928a22
Good: Can write to mount point
================================================
Management server is 10.1.27.14. Checking connectivity.
Good: Can connect to management server 10.1.27.14 port 8250
================================================
Good: Java process is running
================================================
Tests Complete. Look for ERROR or WARNING above.
bkrajendra commented 1 year ago

restarting the secondary storage VM removed the alert and now I can see the secondary storage properly represented in Dashboard. I am testing ISO registration/download. It's working fine and the download has started. I hope eventually I'll be able to start my VM instance today.

This is the 4th time I am deploying CloudStack. Every time I learned new things and faced different issues. Thank you, team.

DaanHoogland commented 1 year ago

@bkrajendra I'm closing this. please reopen or create a new issue if you feel the need