After some playing around, I’m able to get the instance up and running again, 
but the issue still exists.

I noticed if I detect the two addition 100G DATADISKs, the instance starts. If 
I reattach the volumes after the instance is running, everything is fine, but 
as soon as I stop the instance and try to start again, I get the same failure. 
Not sure how to find the root cause. Any ideas based on this information? These 
two volumes are configured for lvm. I have many instance with a similar 
configuration with no issues.

Thanks
-jeremy

> On Friday, Nov 17, 2023 at 1:06 AM, Me <[email protected] 
> (mailto:[email protected])> wrote:
>
>
>
>
> > Begin forwarded message:
> >
> > From: Jeremy Hansen <[email protected] 
> > (mailto:[email protected])>
> > Date: Thursday, Nov 16, 2023 at 5:29 PM
> > To: <[email protected] (mailto:[email protected])>
> > Subject: Issue starting a specific VM
> >
> > I noticed that. What’s odd is I made no changes to this VM.
> >
> > Is there a better way to list settings for a VM that isn’t running?
> >
> > Here are screenshots. Basically root and two addition volumes. One nic.
> >
> > Thanks!
> > -jeremy
> >
> >
> >
> > > On Thursday, Nov 16, 2023 at 4:56 PM, Wei ZHOU <[email protected] 
> > > (mailto:[email protected])> wrote:
> > > Hi,
> > >
> > > The logs show
> > >
> > > 2023-11-15 23:00:13,172 WARN [resource.wrapper.LibvirtStartCommandWrapper]
> > > (agentRequest-Handler-3:null) (logid:456eabd2) LibvirtException
> > > org.libvirt.LibvirtException: internal error: Only 1 IDE controller is
> > > supported
> > > at org.libvirt.ErrorHandler.processError(Unknown Source)
> > > at org.libvirt.ErrorHandler.processError(Unknown Source)
> > > at org.libvirt.Connect.domainCreateXML(Unknown Source)
> > > at
> > > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.startVM(LibvirtComputingResource.java:1816)
> > >
> > > How many volumes/nics does the vm have ? Can you list the vm settings ?
> > >
> > >
> > > -Wei
> > >
> > >
> > > On Thu, 16 Nov 2023 at 08:06, Jeremy Hansen <[email protected]>
> > > wrote:
> > >
> > > > I’m having an issue with a specific VM being unable to start and I’m not
> > > > quite sure why or how it got in this state.
> > > >
> > > > cloudstack 4.18.1.0
> > > >
> > > > Management log:
> > > >
> > > > 2023-11-15 22:56:44,938 ERROR [c.c.a.ApiAsyncJobDispatcher]
> > > > (API-Job-Executor-1:ctx-fc2bc1f9 job-78702) (logid:a3519842) Unexpected
> > > > exception while executing
> > > > org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin
> > > > com.cloud.utils.exception.CloudRuntimeException: Unable to start a VM
> > > > [cc216a54-5d5b-4ec2-a178-474ff957e53f] due to [Unable to create a
> > > > deployment for VM instance
> > > > {"id":218,"instanceName":"i-4-218-VM","type":"User","uuid":"cc216a54-5d5b-4ec2-a178-474ff957e53f"}].
> > > > at
> > > > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:841)
> > > > at
> > > > org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:258)
> > > > at
> > > > org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:214)
> > > > at
> > > > com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:5401)
> > > > at
> > > > com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:5251)
> > > > at
> > > > com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3179)
> > > > at 
> > > > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
> > > > Method)
> > > > at
> > > > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> > > > at
> > > > java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> > > > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> > > > at
> > > > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
> > > > at
> > > > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
> > > > at
> > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
> > > > at
> > > > org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
> > > > at
> > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
> > > > at
> > > > com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:52)
> > > > at
> > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
> > > > at
> > > > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
> > > > at
> > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
> > > > at
> > > > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
> > > > at com.sun.proxy.$Proxy185.startVirtualMachine(Unknown Source)
> > > > at
> > > > org.apache.cloudstack.api.command.user.vm.StartVMCmd.execute(StartVMCmd.java:181)
> > > > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:163)
> > > > at
> > > > com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:112)
> > > > 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)
> > > > Caused by: com.cloud.exception.InsufficientServerCapacityException: 
> > > > Unable
> > > > to create a deployment for VM instance
> > > > {"id":218,"instanceName":"i-4-218-VM","type":"User","uuid":"cc216a54-5d5b-4ec2-a178-474ff957e53f"}Scope=interface
> > > > com.cloud.dc.DataCenter; id=1
> > > > at
> > > > com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1226)
> > > > at
> > > > com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5412)
> > > > at 
> > > > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
> > > > Method)
> > > > ... 18 more
> > > >
> > > > Compute node logs:
> > > >
> > > > ==> agent.log <==
> > > > 2023-11-15 23:00:10,017 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:10,200 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:10,377 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:10,528 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:10,822 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:11,071 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:11,250 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:11,418 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:11,587 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:11,756 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:12,092 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:12,100 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:12,386 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:12,436 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:12,603 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:12,751 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:12,952 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Attempting to create 
> > > > storage
> > > > pool 611ef480-1caa-3e50-a6a0-c3d666dfd52f (NetworkFilesystem) in libvirt
> > > > 2023-11-15 23:00:12,954 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Found existing defined
> > > > storage pool 611ef480-1caa-3e50-a6a0-c3d666dfd52f, using it.
> > > > 2023-11-15 23:00:12,954 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Trying to fetch storage 
> > > > pool
> > > > 611ef480-1caa-3e50-a6a0-c3d666dfd52f from libvirt
> > > > 2023-11-15 23:00:12,973 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:13,070 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:13,076 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:13,084 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:13,143 WARN [kvm.resource.LibvirtKvmAgentHook]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Groovy script
> > > > '/etc/cloudstack/agent/hooks/libvirt-vm-xml-transformer.groovy' is not
> > > > available. Transformations will not be applied.
> > > > 2023-11-15 23:00:13,143 WARN [kvm.resource.LibvirtKvmAgentHook]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Groovy scripting engine 
> > > > is
> > > > not initialized. Data transformation skipped.
> > > > 2023-11-15 23:00:13,172 WARN
> > > > [resource.wrapper.LibvirtStartCommandWrapper]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) LibvirtException
> > > > org.libvirt.LibvirtException: internal error: Only 1 IDE controller is
> > > > supported
> > > > at org.libvirt.ErrorHandler.processError(Unknown Source)
> > > > at org.libvirt.ErrorHandler.processError(Unknown Source)
> > > > at org.libvirt.Connect.domainCreateXML(Unknown Source)
> > > > at
> > > > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.startVM(LibvirtComputingResource.java:1816)
> > > > at
> > > > com.cloud.hypervisor.kvm.resource.wrapper.LibvirtStartCommandWrapper.execute(LibvirtStartCommandWrapper.java:89)
> > > > 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:1848)
> > > > at com.cloud.agent.Agent.processRequest(Agent.java:662)
> > > > at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1082)
> > > > at com.cloud.utils.nio.Task.call(Task.java:83)
> > > > at com.cloud.utils.nio.Task.call(Task.java:29)
> > > > 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)
> > > > 2023-11-15 23:00:13,190 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:13,241 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:13,247 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:13,300 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-3:null) (logid:456eabd2) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:13,399 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:13,576 INFO [kvm.resource.LibvirtConnection]
> > > > (agentRequest-Handler-5:null) (logid:456eabd2) No existing libvirtd
> > > > connection found. Opening a new one
> > > > 2023-11-15 23:00:13,578 WARN [kvm.resource.LibvirtConnection]
> > > > (agentRequest-Handler-5:null) (logid:456eabd2) Can not find a connection
> > > > for Instance i-4-218-VM. Assuming the default connection.
> > > > 2023-11-15 23:00:13,586 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > > 2023-11-15 23:00:13,747 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > >
> > > > ==> security_group.log <==
> > > > 2023-11-15 23:00:13,762 - Executing command: 
> > > > destroy_network_rules_for_vm
> > > > 2023-11-15 23:00:13,763 - iptables-save | awk
> > > > '/BF(.*)physdev-is-bridged(.*)i-4-218-def/ { sub(/-A/, "-D", $1) ; 
> > > > print }'
> > > > 2023-11-15 23:00:13,775 - ip6tables-save | awk
> > > > '/BF(.*)physdev-is-bridged(.*)i-4-218-def/ { sub(/-A/, "-D", $1) ; 
> > > > print }'
> > > > 2023-11-15 23:00:13,787 - ebtables -t nat -L PREROUTING | grep 
> > > > i-4-218-VM
> > > > 2023-11-15 23:00:13,800 - Command exited non-zero: ebtables -t nat -L
> > > > PREROUTING | grep i-4-218-VM
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'ebtables -t nat -L PREROUTING |
> > > > grep i-4-218-VM' returned non-zero exit status 1.
> > > > 2023-11-15 23:00:13,803 - ebtables -t nat -L POSTROUTING | grep 
> > > > i-4-218-VM
> > > > 2023-11-15 23:00:13,816 - Command exited non-zero: ebtables -t nat -L
> > > > POSTROUTING | grep i-4-218-VM
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'ebtables -t nat -L POSTROUTING |
> > > > grep i-4-218-VM' returned non-zero exit status 1.
> > > > 2023-11-15 23:00:13,816 - ebtables -t nat -F i-4-218-VM-in
> > > > 2023-11-15 23:00:13,827 - Command exited non-zero: ebtables -t nat -F
> > > > i-4-218-VM-in
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'ebtables -t nat -F 
> > > > i-4-218-VM-in'
> > > > returned non-zero exit status 1.
> > > > 2023-11-15 23:00:13,828 - Ignoring failure to delete ebtables chain for 
> > > > vm
> > > > i-4-218-VM
> > > > 2023-11-15 23:00:13,828 - ebtables -t nat -F i-4-218-VM-out
> > > > 2023-11-15 23:00:13,840 - Command exited non-zero: ebtables -t nat -F
> > > > i-4-218-VM-out
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'ebtables -t nat -F 
> > > > i-4-218-VM-out'
> > > > returned non-zero exit status 1.
> > > > 2023-11-15 23:00:13,840 - Ignoring failure to delete ebtables chain for 
> > > > vm
> > > > i-4-218-VM
> > > > 2023-11-15 23:00:13,840 - ebtables -t nat -F i-4-218-VM-in-ips
> > > > 2023-11-15 23:00:13,852 - Command exited non-zero: ebtables -t nat -F
> > > > i-4-218-VM-in-ips
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'ebtables -t nat -F
> > > > i-4-218-VM-in-ips' returned non-zero exit status 1.
> > > > 2023-11-15 23:00:13,853 - Ignoring failure to delete ebtables chain for 
> > > > vm
> > > > i-4-218-VM
> > > > 2023-11-15 23:00:13,853 - ebtables -t nat -F i-4-218-VM-out-ips
> > > > 2023-11-15 23:00:13,864 - Command exited non-zero: ebtables -t nat -F
> > > > i-4-218-VM-out-ips
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'ebtables -t nat -F
> > > > i-4-218-VM-out-ips' returned non-zero exit status 1.
> > > > 2023-11-15 23:00:13,864 - Ignoring failure to delete ebtables chain for 
> > > > vm
> > > > i-4-218-VM
> > > > 2023-11-15 23:00:13,864 - ebtables -t nat -F i-4-218-VM-in-src
> > > > 2023-11-15 23:00:13,875 - Command exited non-zero: ebtables -t nat -F
> > > > i-4-218-VM-in-src
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'ebtables -t nat -F
> > > > i-4-218-VM-in-src' returned non-zero exit status 1.
> > > > 2023-11-15 23:00:13,876 - Ignoring failure to delete ebtables chain for 
> > > > vm
> > > > i-4-218-VM
> > > > 2023-11-15 23:00:13,876 - ebtables -t nat -F i-4-218-VM-out-dst
> > > > 2023-11-15 23:00:13,887 - Command exited non-zero: ebtables -t nat -F
> > > > i-4-218-VM-out-dst
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'ebtables -t nat -F
> > > > i-4-218-VM-out-dst' returned non-zero exit status 1.
> > > > 2023-11-15 23:00:13,888 - Ignoring failure to delete ebtables chain for 
> > > > vm
> > > > i-4-218-VM
> > > > 2023-11-15 23:00:13,888 - iptables -F i-4-218-def
> > > > 2023-11-15 23:00:13,896 - Command exited non-zero: iptables -F 
> > > > i-4-218-def
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'iptables -F i-4-218-def' 
> > > > returned
> > > > non-zero exit status 1.
> > > > 2023-11-15 23:00:13,897 - Ignoring failure to flush chain: i-4-218-def
> > > > 2023-11-15 23:00:13,897 - iptables -F i-4-218-VM
> > > > 2023-11-15 23:00:13,906 - Command exited non-zero: iptables -F 
> > > > i-4-218-VM
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'iptables -F i-4-218-VM' returned
> > > > non-zero exit status 1.
> > > > 2023-11-15 23:00:13,907 - Ignoring failure to flush chain: i-4-218-VM
> > > > 2023-11-15 23:00:13,907 - iptables -F i-4-218-VM-eg
> > > > 2023-11-15 23:00:13,915 - Command exited non-zero: iptables -F
> > > > i-4-218-VM-eg
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'iptables -F i-4-218-VM-eg'
> > > > returned non-zero exit status 1.
> > > > 2023-11-15 23:00:13,916 - Ignoring failure to flush chain: i-4-218-VM-eg
> > > > 2023-11-15 23:00:13,916 - iptables -X i-4-218-def
> > > >
> > > > ==> agent.log <==
> > > > 2023-11-15 23:00:13,916 INFO [kvm.storage.LibvirtStorageAdaptor]
> > > > (agentRequest-Handler-4:null) (logid:5281116a) Trying to fetch storage 
> > > > pool
> > > > b221bcf2-819c-37c7-b007-bf7749ab468b from libvirt
> > > >
> > > > ==> security_group.log <==
> > > > 2023-11-15 23:00:13,925 - Command exited non-zero: iptables -X 
> > > > i-4-218-def
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'iptables -X i-4-218-def' 
> > > > returned
> > > > non-zero exit status 1.
> > > > 2023-11-15 23:00:13,925 - Ignoring failure to delete chain: i-4-218-def
> > > > 2023-11-15 23:00:13,926 - iptables -X i-4-218-VM
> > > > 2023-11-15 23:00:13,934 - Command exited non-zero: iptables -X 
> > > > i-4-218-VM
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'iptables -X i-4-218-VM' returned
> > > > non-zero exit status 1.
> > > > 2023-11-15 23:00:13,935 - Ignoring failure to delete chain: i-4-218-VM
> > > > 2023-11-15 23:00:13,935 - iptables -X i-4-218-VM-eg
> > > > 2023-11-15 23:00:13,943 - Command exited non-zero: iptables -X
> > > > i-4-218-VM-eg
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'iptables -X i-4-218-VM-eg'
> > > > returned non-zero exit status 1.
> > > > 2023-11-15 23:00:13,944 - Ignoring failure to delete chain: 
> > > > i-4-218-VM-eg
> > > > 2023-11-15 23:00:13,944 - ipset -F i-4-218-VM
> > > > 2023-11-15 23:00:13,951 - Command exited non-zero: ipset -F i-4-218-VM
> > > > Traceback (most recent call last):
> > > > File
> > > > "/usr/share/cloudstack-common/scripts/vm/network/security_group.py", 
> > > > line
> > > > 53, in execute
> > > > return check_output(cmd, shell=True).decode()
> > > > File "/usr/lib64/python3.9/subprocess.py", line 424, in check_output
> > > > return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
> > > > File "/usr/lib64/python3.9/subprocess.py", line 528, in run
> > > > raise CalledProcessError(retcode, process.args,
> > > > subprocess.CalledProcessError: Command 'ipset -F i-4-218-VM' returned
> > > > non-zero exit status 1.
> > > > 2023-11-15 23:00:13,952 - Ignoring failure to delete ipset i-4-218-VM
> > > > 2023-11-15 23:00:13,952 - Failed to delete rule log file
> > > > /var/run/cloud/i-4-218-VM.log
> > > > 2023-11-15 23:00:13,952 - Failed to delete rule log file
> > > > /var/run/cloud/i-4-218-VM.ip
> > > >
> > > > Any clues on how to debug this? All my other instances are working fine.
> > > > I’ve restarted libvirtd, agent, management.
> > > >
> > > > Thanks
> > > > -jeremy
> > > >
> > > >
> > > >
> > > >

Attachment: signature.asc
Description: PGP signature

Reply via email to