NetworkManager ? I though it was advised to not run it...
On 18 May 2018 at 16:11, Simon Weller <swel...@ena.com.invalid> wrote:
> Ben,
>
>
> Can you put the KVM agent in debug mode and post the logs?
>
>
> sed -i 's/INFO/DEBUG/g' /etc/cloudstack/agent/log4j-cloud.xml
>
>
> Then restart the agent.
>
>
> - Si
>
>
> ________________________________
> From: Benjamin Naber <benjamin.na...@coders-area.de>
> Sent: Friday, May 18, 2018 2:20 AM
> To: Cloudstack Mailinglist
> Subject: KVM Problem by deploying VPC
>
> Hi Together,
>
> im currently testing the Configuration of KVM Hosts in our Test
> environment.
> When i try to deploy a VPC the Hypervisor shows me the following error:
>
> Hypervisor Log:
>
> May 18 09:12:08 kvm-test01-sb dbus[883]: [system] Successfully activated
> service 'org.freedesktop.nm_dispatcher'
> May 18 09:12:08 kvm-test01-sb systemd: Started Network Manager Script
> Dispatcher Service.
> May 18 09:12:08 kvm-test01-sb nm-dispatcher: req:1 'up' [vnet0]: new
> request (4 scripts)
> May 18 09:12:08 kvm-test01-sb nm-dispatcher: req:1 'up' [vnet0]: start
> running ordered scripts...
> May 18 09:12:08 kvm-test01-sb libvirtd: 2018-05-18 07:12:08.667+0000:
> 6251: warning : qemuDomainObjTaint:5378 : Domain id=2 name='r-31-VM'
> uuid=ff22b439-e0d0-44d1-a3cc-8dd23afb82eb is tainted: high-privileges
> May 18 09:12:08 kvm-test01-sb dbus[883]: [system] Activating via systemd:
> service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.
> machine1.service'
> May 18 09:12:08 kvm-test01-sb systemd: Starting Virtual Machine and
> Container Registration Service...
> May 18 09:12:08 kvm-test01-sb dbus[883]: [system] Successfully activated
> service 'org.freedesktop.machine1'
> May 18 09:12:08 kvm-test01-sb systemd: Started Virtual Machine and
> Container Registration Service.
> May 18 09:12:08 kvm-test01-sb systemd-machined: New machine qemu-2-r-31-VM.
> May 18 09:12:08 kvm-test01-sb systemd: Started Virtual Machine
> qemu-2-r-31-VM.
> May 18 09:12:08 kvm-test01-sb systemd: Starting Virtual Machine
> qemu-2-r-31-VM.
> May 18 09:12:08 kvm-test01-sb systemd: Unit iscsi.service cannot be
> reloaded because it is inactive.
> May 18 09:12:08 kvm-test01-sb kvm: 1 guest now active
> May 18 09:12:12 kvm-test01-sb kernel: kvm [48292]: vcpu0 disabled perfctr
> wrmsr: 0xc1 data 0xabcd
> May 18 09:12:44 kvm-test01-sb kernel: kvm [48292]: vcpu0 disabled perfctr
> wrmsr: 0xc1 data 0xabcd
> May 18 09:12:46 kvm-test01-sb sh: INFO [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-5:) (logid:b911ffae) Trying to fetch storage pool
> 2258aa76-7813-354d-b274-961fb337e716 from libvirt
> May 18 09:12:46 kvm-test01-sb sh: INFO [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-5:) (logid:b911ffae) Asking libvirt to refresh
> storage pool 2258aa76-7813-354d-b274-961fb337e716
> May 18 09:13:05 kvm-test01-sb NetworkManager[925]: <info>
> [1526627585.6454] manager: (enp8s0f0.233): new VLAN device
> (/org/freedesktop/NetworkManager/Devices/15)
> May 18 09:13:05 kvm-test01-sb NetworkManager[925]: <info>
> [1526627585.6470] device (enp8s0f0.233): carrier: link connected
> May 18 09:13:05 kvm-test01-sb kernel: brenp8s0f0-233: port 1(enp8s0f0.233)
> entered blocking state
> May 18 09:13:05 kvm-test01-sb kernel: brenp8s0f0-233: port 1(enp8s0f0.233)
> entered disabled state
> May 18 09:13:05 kvm-test01-sb kernel: device enp8s0f0.233 entered
> promiscuous mode
> May 18 09:13:05 kvm-test01-sb kernel: brenp8s0f0-233: port 2(vnet1)
> entered blocking state
> May 18 09:13:05 kvm-test01-sb kernel: brenp8s0f0-233: port 2(vnet1)
> entered disabled state
> May 18 09:13:05 kvm-test01-sb kernel: device vnet1 entered promiscuous mode
> May 18 09:13:05 kvm-test01-sb NetworkManager[925]: <info>
> [1526627585.6648] manager: (vnet1): new Tun device (/org/freedesktop/
> NetworkManager/Devices/16)
> May 18 09:13:05 kvm-test01-sb NetworkManager[925]: <info>
> [1526627585.6662] device (vnet1): state change: unmanaged -> unavailable
> (reason 'connection-assumed', sys-iface-state: 'external')
> May 18 09:13:05 kvm-test01-sb NetworkManager[925]: <info>
> [1526627585.6674] device (vnet1): state change: unavailable -> disconnected
> (reason 'none', sys-iface-state: 'external')
> May 18 09:13:10 kvm-test01-sb kernel: cloud0: port 1(vnet0) entered
> disabled state
> May 18 09:13:10 kvm-test01-sb kernel: device vnet0 left promiscuous mode
> May 18 09:13:10 kvm-test01-sb kernel: cloud0: port 1(vnet0) entered
> disabled state
> May 18 09:13:10 kvm-test01-sb NetworkManager[925]: <info>
> [1526627590.5339] device (vnet0): state change: activated -> unmanaged
> (reason 'unmanaged', sys-iface-state: 'removed')
> May 18 09:13:10 kvm-test01-sb NetworkManager[925]: <info>
> [1526627590.5342] device (cloud0): bridge port vnet0 was detached
> May 18 09:13:10 kvm-test01-sb NetworkManager[925]: <info>
> [1526627590.5342] device (vnet0): released from master device cloud0
> May 18 09:13:10 kvm-test01-sb dbus[883]: [system] Activating via systemd:
> service name='org.freedesktop.nm_dispatcher'
> unit='dbus-org.freedesktop.nm-dispatcher.service'
> May 18 09:13:10 kvm-test01-sb systemd: Starting Network Manager Script
> Dispatcher Service...
> May 18 09:13:10 kvm-test01-sb kernel: device vnet1 left promiscuous mode
> May 18 09:13:10 kvm-test01-sb kernel: brenp8s0f0-233: port 2(vnet1)
> entered disabled state
> May 18 09:13:10 kvm-test01-sb dbus[883]: [system] Successfully activated
> service 'org.freedesktop.nm_dispatcher'
> May 18 09:13:10 kvm-test01-sb systemd: Started Network Manager Script
> Dispatcher Service.
> May 18 09:13:10 kvm-test01-sb nm-dispatcher: req:1 'down' [vnet0]: new
> request (4 scripts)
> May 18 09:13:10 kvm-test01-sb nm-dispatcher: req:1 'down' [vnet0]: start
> running ordered scripts...
> May 18 09:13:10 kvm-test01-sb NetworkManager[925]: <info>
> [1526627590.5772] device (vnet1): state change: disconnected -> unmanaged
> (reason 'unmanaged', sys-iface-state: 'removed')
> May 18 09:13:10 kvm-test01-sb NetworkManager[925]: <info>
> [1526627590.5772] device (vnet1): released from master device brenp8s0f0-233
> May 18 09:13:10 kvm-test01-sb libvirtd: 2018-05-18 07:13:10.596+0000:
> 1519: error : qemuMonitorIO:704 : internal error: End of file from qemu
> monitor
> May 18 09:13:10 kvm-test01-sb kvm: 0 guests now active
> May 18 09:13:10 kvm-test01-sb systemd-machined: Machine qemu-2-r-31-VM
> terminated.
> May 18 09:13:11 kvm-test01-sb sh: libvirt: QEMU Driver error : Domain not
> found: no domain with matching uuid 'ff22b439-e0d0-44d1-a3cc-8dd23afb82eb'
> (r-31-VM)
> May 18 09:13:11 kvm-test01-sb kernel: device enp8s0f0.233 left promiscuous
> mode
> May 18 09:13:11 kvm-test01-sb kernel: brenp8s0f0-233: port 1(enp8s0f0.233)
> entered disabled state
> May 18 09:13:11 kvm-test01-sb NetworkManager[925]: <info>
> [1526627591.2137] device (enp8s0f0.233): released from master device
> brenp8s0f0-233
> May 18 09:13:11 kvm-test01-sb sh: libvirt: QEMU Driver error : Domain not
> found: no domain with matching name 'r-31-VM'
> May 18 09:13:11 kvm-test01-sb sh: INFO [kvm.resource.LibvirtConnection]
> (agentRequest-Handler-3:) (logid:94c38c31) No existing libvirtd connection
> found. Opening a new one
> May 18 09:13:11 kvm-test01-sb sh: libvirt: LXC Driver error : Domain not
> found: No domain with matching name 'r-31-VM'
> May 18 09:13:11 kvm-test01-sb sh: WARN [kvm.resource.LibvirtConnection]
> (agentRequest-Handler-3:) (logid:94c38c31) Can not find a connection for
> Instance r-31-VM. Assuming the default connection.
> May 18 09:13:11 kvm-test01-sb sh: libvirt: QEMU Driver error : Domain not
> found: no domain with matching name 'r-31-VM'
> May 18 09:13:11 kvm-test01-sb sh: libvirt: QEMU Driver error : Domain not
> found: no domain with matching name 'r-31-VM'
> May 18 09:13:11 kvm-test01-sb sh: libvirt: QEMU Driver error : Domain not
> found: no domain with matching name 'r-31-VM'
> May 18 09:13:11 kvm-test01-sb sh: libvirt: QEMU Driver error : Domain not
> found: no domain with matching name 'r-31-VM'
> May 18 09:13:11 kvm-test01-sb sh: libvirt: QEMU Driver error : Domain not
> found: no domain with matching name 'r-31-VM'
>
> CS Management Exception:
>
> 2018-05-18 09:13:11,284 ERROR [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-30:ctx-67604a44 job-169/job-170 ctx-ec9dfbf1)
> (logid:94c38c31) Failed to start instance VM[DomainRouter|r-31-VM]
> com.cloud.utils.exception.ExecutionException: Unable to start
> VM:ff22b439-e0d0-44d1-a3cc-8dd23afb82eb due to error in finalizeStart,
> not retrying
> at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(
> VirtualMachineManagerImpl.java:1099)
> at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(
> VirtualMachineManagerImpl.java:4691)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(
> NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(
> DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(
> VmWorkJobHandlerProxy.java:107)
> at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(
> VirtualMachineManagerImpl.java:4852)
> at com.cloud.vm.VmWorkJobDispatcher.runJob(
> VmWorkJobDispatcher.java:102)
> at org.apache.cloudstack.framework.jobs.impl.
> AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:558)
> at org.apache.cloudstack.managed.context.
> ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> at org.apache.cloudstack.managed.context.impl.
> DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at org.apache.cloudstack.managed.context.impl.
> DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at org.apache.cloudstack.managed.context.impl.
> DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at org.apache.cloudstack.managed.context.
> ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> at org.apache.cloudstack.framework.jobs.impl.
> AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:506)
> at java.util.concurrent.Executors$RunnableAdapter.
> call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(
> ThreadPoolExecutor.java:1149)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)
> 2018-05-18 09:13:11,289 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-30:ctx-67604a44 job-169/job-170 ctx-ec9dfbf1)
> (logid:94c38c31) Cleaning up resources for the vm VM[DomainRouter|r-31-VM]
> in Starting state
> 2018-05-18 09:13:11,291 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-30:ctx-67604a44
> job-169/job-170 ctx-ec9dfbf1) (logid:94c38c31) Seq 10-6761873365520090721:
> Sending { Cmd , MgmtId: 109952567336, via: 10(kvm-test01-sb), Ver: v1,
> Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,
> "checkBeforeCleanup":false,"forceStop":false,"vmName":"r-
> 31-VM","executeInSequence":false,"wait":0}}] }
> 2018-05-18 09:13:11,627 DEBUG [c.c.a.t.Request]
> (AgentManager-Handler-14:null) (logid:) Seq 10-6761873365520090721:
> Processing: { Ans: , MgmtId: 109952567336, via: 10, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
> 2018-05-18 09:13:11,627 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-30:ctx-67604a44
> job-169/job-170 ctx-ec9dfbf1) (logid:94c38c31) Seq 10-6761873365520090721:
> Received: { Ans: , MgmtId: 109952567336, via: 10(kvm-test01-sb), Ver: v1,
> Flags: 10, { StopAnswer } }
> 2018-05-18 09:13:11,639 DEBUG [c.c.n.g.ControlNetworkGuru]
> (Work-Job-Executor-30:ctx-67604a44 job-169/job-170 ctx-ec9dfbf1)
> (logid:94c38c31) Released nic: NicProfile[65-31-null-null-null
> 2018-05-18 09:13:11,646 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-30:ctx-67604a44 job-169/job-170 ctx-ec9dfbf1)
> (logid:94c38c31) Successfully released network resources for the vm
> VM[DomainRouter|r-31-VM]
> 2018-05-18 09:13:11,646 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-30:ctx-67604a44 job-169/job-170 ctx-ec9dfbf1)
> (logid:94c38c31) Successfully cleanued up resources for the vm
> VM[DomainRouter|r-31-VM] in Starting state
>
> Deployment of Isolatet Networks and redundant VPCs, works wothout any
> problems.
>
> CS Version: 4.10
> KVM Host: CentOS 7.4 minimal (libvirt-3.9.0-14.el7_5.2.x86_64,
> qemu-kvm-1.5.3-156.el7.x86_64, kernel-3.10.0-693.el7.x86_64)
>
> Someone got an i idea ?
>
> Kind regards
>
> Ben
>
--
Andrija Panić
