[ovs-discuss] OVS stops working after 1 hour with repetitive errors in neutron-openvswitch-agent.log

Matthias Hüther matthias.huether at twenty20.eu
Mon Dec 17 12:14:36 UTC 2018


Hi Ben, 

in my last mail I try with gdb and backtrace. now I restarted the ovs-vswitched service again, waited for the error and try to get a core dump by killing the revalidator-thread with SEGV Signal.
See my mail attachment, hope that helps.

Greetings Matthias




> Am 17.12.2018 um 11:06 schrieb Matthias Hüther <matthias.huether at twenty20.eu>:
> 
> Sorry, this is my first time that I'm making a backtrace. I hope I did it correctly.
> 
> 
> OVS log shows:
> 
> 
> root at B3105-BS2-03:/var/log/openvswitch# tail ovs-vswitchd.log
> 2018-12-17T09:29:47.151Z|00069|ovs_rcu|WARN|blocked 64001 ms waiting for revalidator33 to quiesce
> 2018-12-17T09:29:58.255Z|00007|ovs_rcu(urcu5)|WARN|blocked 64002 ms waiting for revalidator33 to quiesce
> 2018-12-17T09:30:51.150Z|00070|ovs_rcu|WARN|blocked 128000 ms waiting for revalidator33 to quiesce
> 2018-12-17T09:31:02.256Z|00008|ovs_rcu(urcu5)|WARN|blocked 128003 ms waiting for revalidator33 to quiesce
> 2018-12-17T09:32:59.152Z|00071|ovs_rcu|WARN|blocked 256002 ms waiting for revalidator33 to quiesce
> 2018-12-17T09:33:10.256Z|00009|ovs_rcu(urcu5)|WARN|blocked 256003 ms waiting for revalidator33 to quiesce
> 2018-12-17T09:37:15.151Z|00072|ovs_rcu|WARN|blocked 512001 ms waiting for revalidator33 to quiesce
> 2018-12-17T09:37:26.257Z|00010|ovs_rcu(urcu5)|WARN|blocked 512004 ms waiting for revalidator33 to quiesce
> 2018-12-17T09:45:47.155Z|00073|ovs_rcu|WARN|blocked 1024005 ms waiting for revalidator33 to quiesce
> 2018-12-17T09:45:58.261Z|00011|ovs_rcu(urcu5)|WARN|blocked 1024008 ms waiting for revalidator33 to quiesce
> 
> 
> Getting thread-id:
> 
> root at B3105-BS2-03:/var/log/openvswitch# ps -T -p 37783
>   PID  SPID TTY          TIME CMD
> 37783 37783 ?        00:00:02 ovs-vswitchd
> 37783 37802 ?        00:00:01 urcu5
> 37783 37852 ?        00:00:02 handler26
> 37783 37853 ?        00:00:00 handler27
> 37783 37854 ?        00:00:00 handler28
> 37783 37855 ?        00:00:00 handler29
> 37783 37856 ?        00:00:00 handler30
> 37783 37857 ?        00:00:24 revalidator31
> 37783 37858 ?        00:00:20 revalidator32
> 37783 37859 ?        00:00:20 revalidator33
> 
> 
> gdb attach to process 37859
> 
> root at B3105-BS2-03:/var/log/openvswitch# gdb revalidator33 37859
> GNU gdb (Ubuntu 8.1-0ubuntu3) 8.1.0.20180409-git
> Copyright (C) 2018 Free Software Foundation, Inc.
> License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html <http://gnu.org/licenses/gpl.html>>
> This is free software: you are free to change and redistribute it.
> There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
> and "show warranty" for details.
> This GDB was configured as "x86_64-linux-gnu".
> Type "show configuration" for configuration details.
> For bug reporting instructions, please see:
> <http://www.gnu.org/software/gdb/bugs/ <http://www.gnu.org/software/gdb/bugs/>>.
> Find the GDB manual and other documentation resources online at:
> <http://www.gnu.org/software/gdb/documentation/ <http://www.gnu.org/software/gdb/documentation/>>.
> For help, type "help".
> Type "apropos word" to search for commands related to "word"...
> revalidator33: No such file or directory.
> Attaching to process 37859
> Reading symbols from /usr/lib/openvswitch-switch/ovs-vswitchd...(no debugging symbols found)...done.
> Reading symbols from /usr/lib/x86_64-linux-gnu/libssl.so.1.1...(no debugging symbols found)...done.
> Reading symbols from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1...(no debugging symbols found)...done.
> Reading symbols from /lib/x86_64-linux-gnu/libcap-ng.so.0...(no debugging symbols found)...done.
> Reading symbols from /lib/x86_64-linux-gnu/libpthread.so.0...Reading symbols from /usr/lib/debug/.build-id/28/c6aade70b2d40d1f0f3d0a1a0cad1ab816448f.debug...done.
> done.
> [Thread debugging using libthread_db enabled]
> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
> Reading symbols from /lib/x86_64-linux-gnu/librt.so.1...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/librt-2.27.so...done.
> done.
> Reading symbols from /lib/x86_64-linux-gnu/libm.so.6...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libm-2.27.so...done.
> done.
> Reading symbols from /usr/lib/x86_64-linux-gnu/libunbound.so.2...(no debugging symbols found)...done.
> Reading symbols from /lib/x86_64-linux-gnu/libc.so.6...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libc-2.27.so...done.
> done.
> Reading symbols from /lib/x86_64-linux-gnu/libdl.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libdl-2.27.so...done.
> done.
> Reading symbols from /lib64/ld-linux-x86-64.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/ld-2.27.so...done.
> done.
> Reading symbols from /usr/lib/x86_64-linux-gnu/libevent-2.1.so.6...(no debugging symbols found)...done.
> Reading symbols from /usr/lib/x86_64-linux-gnu/libhogweed.so.4...(no debugging symbols found)...done.
> Reading symbols from /usr/lib/x86_64-linux-gnu/libnettle.so.6...(no debugging symbols found)...done.
> Reading symbols from /usr/lib/x86_64-linux-gnu/libgmp.so.10...(no debugging symbols found)...done.
> 0x00007f749137337b in futex_abstimed_wait (private=<optimized out>, abstime=0x0, expected=10, futex_word=0x55deddfdcfe8) at ../sysdeps/unix/sysv/linux/futex-internal.h:172
> 172	../sysdeps/unix/sysv/linux/futex-internal.h: No such file or directory.
> 
> 
> 
> get backtrace:
> 
> (gdb) backtrace
> #0  0x00007f749137337b in futex_abstimed_wait (private=<optimized out>, abstime=0x0, expected=10, futex_word=0x55deddfdcfe8) at ../sysdeps/unix/sysv/linux/futex-internal.h:172
> #1  __pthread_rwlock_rdlock_full (abstime=0x0, rwlock=0x55deddfdcfe8) at pthread_rwlock_common.c:321
> #2  __GI___pthread_rwlock_rdlock (rwlock=0x55deddfdcfe8) at pthread_rwlock_rdlock.c:27
> #3  0x000055dedbe70238 in ?? ()
> #4  0x000055dedbe0566f in ?? ()
> #5  0x000055dedbdc9352 in ?? ()
> #6  0x000055dedbdc940c in ?? ()
> #7  0x000055dedbdb6f42 in ?? ()
> #8  0x000055dedbdb9d77 in ?? ()
> #9  0x000055dedbdba3e9 in ?? ()
> #10 0x000055dedbe70e4f in ?? ()
> #11 0x00007f749136e6db in start_thread (arg=0x7f7487fff700) at pthread_create.c:463
> #12 0x00007f749084788f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
> 
> 
> 
> Is this what you need?
> 
> Greetings Matthias
> 
> 
> 
>> Am 17.12.2018 um 02:10 schrieb Ben Pfaff <blp at ovn.org <mailto:blp at ovn.org>>:
>> 
>> Well, it sounds like the revalidator31 thread is stuck.  If you can get
>> a backtrace for that thread, perhaps by attaching to it with GDB or by
>> killing the process with a signal like SEGV and looking into the core
>> dump, then it's likely we can figure it out.
>> 
>> On Sun, Dec 16, 2018 at 10:24:43PM +0100, Matthias Hüther wrote:
>>> Hi, thanks for your quick answer.
>>> 
>>> The services do not crash. They keep running, but I think they only blocked / freezed...
>>> 
>>> At the time of the error, I could only find the following logs in ovs-vswitchd.log
>>> 
>>> 
>>> 2018-12-16T20:15:55.991Z|00127|ovs_rcu|WARN|blocked 1001 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:15:56.155Z|00001|ovs_rcu(urcu5)|WARN|blocked 1000 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:15:56.991Z|00128|ovs_rcu|WARN|blocked 2000 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:15:57.156Z|00002|ovs_rcu(urcu5)|WARN|blocked 2001 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:15:58.991Z|00129|ovs_rcu|WARN|blocked 4000 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:15:59.155Z|00003|ovs_rcu(urcu5)|WARN|blocked 4000 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:16:02.991Z|00130|ovs_rcu|WARN|blocked 8000 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:16:03.155Z|00004|ovs_rcu(urcu5)|WARN|blocked 8000 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:16:10.991Z|00131|ovs_rcu|WARN|blocked 16000 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:16:11.155Z|00005|ovs_rcu(urcu5)|WARN|blocked 16000 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:16:26.991Z|00132|ovs_rcu|WARN|blocked 32000 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:16:27.155Z|00006|ovs_rcu(urcu5)|WARN|blocked 32000 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:16:58.992Z|00133|ovs_rcu|WARN|blocked 64001 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:16:59.157Z|00007|ovs_rcu(urcu5)|WARN|blocked 64002 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:18:02.993Z|00134|ovs_rcu|WARN|blocked 128002 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:18:03.157Z|00008|ovs_rcu(urcu5)|WARN|blocked 128002 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:20:10.996Z|00135|ovs_rcu|WARN|blocked 256005 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:20:11.157Z|00009|ovs_rcu(urcu5)|WARN|blocked 256002 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:24:26.997Z|00136|ovs_rcu|WARN|blocked 512006 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:24:27.161Z|00010|ovs_rcu(urcu5)|WARN|blocked 512006 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:32:58.998Z|00137|ovs_rcu|WARN|blocked 1024007 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:32:59.162Z|00011|ovs_rcu(urcu5)|WARN|blocked 1024007 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:50:03.002Z|00138|ovs_rcu|WARN|blocked 2048011 ms waiting for revalidator31 to quiesce
>>> 2018-12-16T20:50:03.166Z|00012|ovs_rcu(urcu5)|WARN|blocked 2048011 ms waiting for revalidator31 to quiesce
>>> 
>>> Unfortunately, I do not know how to deploy core dumps / backtraces in this case.
>>> I have autodeployed OVS via Canonical Juju. Unfortunately, I'm not sure if I can easily update the OVS-Version regardless of the charm version of Juju. https://jujucharms.com/neutron-gateway/ <https://jujucharms.com/neutron-gateway/><https://jujucharms.com/neutron-gateway/ <https://jujucharms.com/neutron-gateway/>>
>>> I have to test that first.
>>> 
>>> After the error I can reload the service ovs-vswitchd  an all work fine for ca 20-60 minutes.
>>> 
>>> Here is the syslog while restarting the ovs-vswitchd service. Maybe this information can help.
>>> 
>>> 
>>> Dec 16 19:52:19 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 19:54:23 C117-BS1-01 systemd[1]: Stopping Open vSwitch Forwarding Unit...
>>> Dec 16 19:54:23 C117-BS1-01 ovs-ctl[47583]:  * Exiting ovs-vswitchd (30099)
>>> Dec 16 19:54:23 C117-BS1-01 systemd-networkd[781]: gre_sys: Lost carrier
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441110.889725] device gre_sys left promiscuous mode
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: reading /etc/resolv.conf
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: Failed to request link: No such device
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using local addresses only for domain lxd
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using nameserver 127.0.0.53#53
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: ERROR:Failed to get interface "gre_sys" status: Command '['/bin/networkctl', 'status', '--no-pager', '--no-legend', '--', 'gre_sys']' returned non-zero exit status 1.
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: reading /etc/resolv.conf
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using local addresses only for domain lxd
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using nameserver 127.0.0.53#53
>>> Dec 16 19:54:23 C117-BS1-01 systemd[1]: Stopped Open vSwitch Forwarding Unit.
>>> Dec 16 19:54:23 C117-BS1-01 systemd[1]: Starting Open vSwitch Forwarding Unit...
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.145535] validate_nla: 20 callbacks suppressed
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.145536] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.145580] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.145644] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.145694] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.145739] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.145790] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.145934] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.145997] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.146043] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.146086] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
>>> Dec 16 19:54:23 C117-BS1-01 systemd-udevd[47734]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
>>> Dec 16 19:54:23 C117-BS1-01 systemd-udevd[47734]: Could not generate persistent MAC address for gre_sys: No such file or directory
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: WARNING:Unknown index 89 seen, reloading interface list
>>> Dec 16 19:54:23 C117-BS1-01 systemd-networkd[781]: gre_sys: Lost carrier
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.187585] device gre_sys entered promiscuous mode
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.190629] device gre_sys left promiscuous mode
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: reading /etc/resolv.conf
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using local addresses only for domain lxd
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using nameserver 127.0.0.53#53
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: reading /etc/resolv.conf
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using local addresses only for domain lxd
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using nameserver 127.0.0.53#53
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: reading /etc/resolv.conf
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using local addresses only for domain lxd
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using nameserver 127.0.0.53#53
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: ERROR:Unknown interface index 89 seen even after reload
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: WARNING:Unknown index 89 seen, reloading interface list
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: ERROR:Unknown interface index 89 seen even after reload
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: WARNING:Unknown index 89 seen, reloading interface list
>>> Dec 16 19:54:23 C117-BS1-01 systemd-networkd[781]: gre_sys: Gained carrier
>>> Dec 16 19:54:23 C117-BS1-01 systemd-networkd[781]: gre_sys: Lost carrier
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.225207] device gre_sys entered promiscuous mode
>>> Dec 16 19:54:23 C117-BS1-01 systemd-udevd[47745]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: reading /etc/resolv.conf
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using local addresses only for domain lxd
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using nameserver 127.0.0.53#53
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.228769] device gre_sys left promiscuous mode
>>> Dec 16 19:54:23 C117-BS1-01 systemd-udevd[47745]: link_config: could not get ethtool features for gre_sys
>>> Dec 16 19:54:23 C117-BS1-01 systemd-udevd[47745]: Could not set offload features of gre_sys: No such device
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: reading /etc/resolv.conf
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using local addresses only for domain lxd
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using nameserver 127.0.0.53#53
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: ERROR:Unknown interface index 89 seen even after reload
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: WARNING:Unknown index 90 seen, reloading interface list
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: ERROR:Unknown interface index 90 seen even after reload
>>> Dec 16 19:54:23 C117-BS1-01 systemd-networkd[781]: gre_sys: Gained carrier
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: WARNING:Unknown index 90 seen, reloading interface list
>>> Dec 16 19:54:23 C117-BS1-01 systemd-udevd[47755]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
>>> Dec 16 19:54:23 C117-BS1-01 systemd-udevd[47755]: Could not generate persistent MAC address for gre_sys: No such file or directory
>>> Dec 16 19:54:23 C117-BS1-01 kernel: [441111.256490] device gre_sys entered promiscuous mode
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: reading /etc/resolv.conf
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using local addresses only for domain lxd
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using nameserver 127.0.0.53#53
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: ERROR:Unknown interface index 90 seen even after reload
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: WARNING:Unknown index 90 seen, reloading interface list
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: reading /etc/resolv.conf
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using local addresses only for domain lxd
>>> Dec 16 19:54:23 C117-BS1-01 dnsmasq[2177]: using nameserver 127.0.0.53#53
>>> Dec 16 19:54:23 C117-BS1-01 networkd-dispatcher[993]: ERROR:Unknown interface index 90 seen even after reload
>>> Dec 16 19:54:23 C117-BS1-01 ovs-vswitchd: ovs|00001|odp_util(revalidator33)|ERR|invalid Ethertype 0 in flow key
>>> Dec 16 19:54:23 C117-BS1-01 ovs-vswitchd: ovs|00002|odp_util(revalidator33)|ERR|invalid Ethertype 0 in flow key
>>> Dec 16 19:54:23 C117-BS1-01 ovs-vswitchd: ovs|00003|odp_util(revalidator33)|ERR|invalid Ethertype 0 in flow key
>>> Dec 16 19:54:23 C117-BS1-01 ovs-vswitchd: ovs|00004|odp_util(revalidator33)|ERR|invalid Ethertype 0 in flow key
>>> Dec 16 19:54:23 C117-BS1-01 ovs-vswitchd: ovs|00005|odp_util(revalidator33)|ERR|invalid Ethertype 0 in flow key
>>> Dec 16 19:54:23 C117-BS1-01 ovs-ctl[47665]:  * Starting ovs-vswitchd
>>> Dec 16 19:54:23 C117-BS1-01 ovs-vsctl: ovs|00001|vsctl|INFO|Called as ovs-vsctl --no-wait set Open_vSwitch . external-ids:hostname=C117-BS1-01.maas
>>> Dec 16 19:54:23 C117-BS1-01 ovs-ctl[47665]:  * Enabling remote OVSDB managers
>>> Dec 16 19:54:23 C117-BS1-01 systemd[1]: Started Open vSwitch Forwarding Unit.
>>> Dec 16 19:54:25 C117-BS1-01 systemd-networkd[781]: gre_sys: Gained IPv6LL
>>> Dec 16 19:54:25 C117-BS1-01 dnsmasq[2177]: reading /etc/resolv.conf
>>> Dec 16 19:54:25 C117-BS1-01 dnsmasq[2177]: using local addresses only for domain lxd
>>> Dec 16 19:54:25 C117-BS1-01 dnsmasq[2177]: using nameserver 127.0.0.53#53
>>> Dec 16 19:55:01 C117-BS1-01 CRON[48709]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 19:55:01 C117-BS1-01 CRON[48707]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 19:56:56 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 19:56:57 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 19:57:28 C117-BS1-01 systemd[1]: Stopping Openstack Neutron Open vSwitch Plugin Agent...
>>> Dec 16 19:57:28 C117-BS1-01 ovsdb-client: ovs|00001|fatal_signal|WARN|terminating with signal 15 (Terminated)
>>> Dec 16 19:57:28 C117-BS1-01 ovsdb-client: ovs|00001|fatal_signal|WARN|terminating with signal 15 (Terminated)
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]: Traceback (most recent call last):
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/eventlet/hubs/hub.py", line 457, in fire_timers
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     timer()
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/eventlet/hubs/timer.py", line 58, in __call__
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     cb(*args, **kw)
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/eventlet/greenthread.py", line 214, in main
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     result = function(*args, **kwargs)
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/ryu/lib/hub.py", line 64, in _launch
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     raise e
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/ryu/lib/hub.py", line 59, in _launch
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     return func(*args, **kwargs)
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ovs_ryuapp.py", line 43, in agent_main_wrapper
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     LOG.exception("Agent main thread died of an exception")
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     self.force_reraise()
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     six.reraise(self.type_, self.value, self.tb)
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/six.py", line 693, in reraise
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     raise value
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ovs_ryuapp.py", line 40, in agent_main_wrapper
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     ovs_agent.main(bridge_classes)
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py", line 2305, in main
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     agent.daemon_loop()
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/osprofiler/profiler.py", line 158, in wrapper
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     result = f(*args, **kwargs)
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py", line 2213, in daemon_loop
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     self.rpc_loop(polling_manager=pm, bridges_monitor=bm)
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3.6/contextlib.py", line 88, in __exit__
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     next(self.gen)
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/neutron/agent/linux/ovsdb_monitor.py", line 50, in get_bridges_monitor
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     mon.stop()
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:   File "/usr/lib/python3/dist-packages/neutron/agent/linux/async_process.py", line 134, in stop
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]:     raise AsyncProcessException(_('Process is not running.'))
>>> Dec 16 19:57:29 C117-BS1-01 neutron-openvswitch-agent[11497]: neutron.agent.linux.async_process.AsyncProcessException: Process is not running.
>>> Dec 16 19:57:30 C117-BS1-01 systemd[1]: neutron-openvswitch-agent.service: Main process exited, code=exited, status=1/FAILURE
>>> Dec 16 19:57:30 C117-BS1-01 systemd[1]: neutron-openvswitch-agent.service: Failed with result 'exit-code'.
>>> Dec 16 19:57:30 C117-BS1-01 systemd[1]: Stopped Openstack Neutron Open vSwitch Plugin Agent.
>>> Dec 16 19:57:30 C117-BS1-01 systemd[1]: Starting Openstack Neutron Open vSwitch Plugin Agent...
>>> Dec 16 19:57:30 C117-BS1-01 systemd[1]: Started Openstack Neutron Open vSwitch Plugin Agent.
>>> Dec 16 19:57:38 C117-BS1-01 ovs-vsctl: ovs|00001|vsctl|INFO|Called as /usr/bin/ovs-vsctl --timeout=5 --id=@manager -- create Manager "target=\"ptcp:6640:127.0.0.1\"" -- add Open_vSwitch . manager_options @manager
>>> Dec 16 19:57:38 C117-BS1-01 ovs-vsctl: ovs|00002|ovsdb_idl|WARN|transaction error: {"details":"Transaction causes multiple rows in \"Manager\" table to have identical values (\"ptcp:6640:127.0.0.1\") for index on column \"target\".  First row,$
>>> Dec 16 19:57:38 C117-BS1-01 ovs-vsctl: ovs|00003|db_ctl_base|ERR|transaction error: {"details":"Transaction causes multiple rows in \"Manager\" table to have identical values (\"ptcp:6640:127.0.0.1\") for index on column \"target\".  First row$
>>> Dec 16 19:57:39 C117-BS1-01 ovs-vsctl: ovs|00001|vsctl|INFO|Called as /usr/bin/ovs-vsctl --timeout=5 --id=@manager -- create Manager "target=\"ptcp:6640:127.0.0.1\"" -- add Open_vSwitch . manager_options @manager
>>> Dec 16 19:57:39 C117-BS1-01 ovs-vsctl: ovs|00002|ovsdb_idl|WARN|transaction error: {"details":"Transaction causes multiple rows in \"Manager\" table to have identical values (\"ptcp:6640:127.0.0.1\") for index on column \"target\".  First row,$
>>> Dec 16 19:57:39 C117-BS1-01 ovs-vsctl: ovs|00003|db_ctl_base|ERR|transaction error: {"details":"Transaction causes multiple rows in \"Manager\" table to have identical values (\"ptcp:6640:127.0.0.1\") for index on column \"target\".  First row$
>>> Dec 16 20:00:01 C117-BS1-01 CRON[58733]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:00:01 C117-BS1-01 CRON[58731]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:02:11 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:02:12 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 20:05:01 C117-BS1-01 CRON[3495]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:05:01 C117-BS1-01 CRON[3492]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:06:50 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:06:51 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 20:10:01 C117-BS1-01 CRON[13639]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:10:01 C117-BS1-01 CRON[13637]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:11:10 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:11:11 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 20:15:01 C117-BS1-01 CRON[23459]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:15:01 C117-BS1-01 CRON[23457]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:16:23 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:16:24 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 20:17:01 C117-BS1-01 CRON[28078]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
>>> Dec 16 20:20:01 C117-BS1-01 CRON[33472]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:20:01 C117-BS1-01 CRON[33470]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:21:50 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:21:51 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 20:25:01 C117-BS1-01 CRON[43354]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:25:01 C117-BS1-01 CRON[43352]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:26:23 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:26:24 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 20:28:48 C117-BS1-01 systemd-resolved[812]: Server returned error NXDOMAIN, mitigating potential DNS violation DVE-2018-0001, retrying transaction with reduced feature level UDP.
>>> Dec 16 20:30:01 C117-BS1-01 CRON[53405]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:30:01 C117-BS1-01 CRON[53403]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:30:34 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:30:35 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 20:35:01 C117-BS1-01 CRON[63281]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:35:01 C117-BS1-01 CRON[63279]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:35:31 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:35:32 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 20:40:01 C117-BS1-01 CRON[8250]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:40:01 C117-BS1-01 CRON[8248]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:41:06 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:41:07 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 20:45:01 C117-BS1-01 CRON[18228]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:45:01 C117-BS1-01 CRON[18226]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:46:44 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:46:45 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 20:50:01 C117-BS1-01 CRON[28090]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:50:01 C117-BS1-01 CRON[28088]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:52:00 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:52:01 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 20:55:01 C117-BS1-01 CRON[37950]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 20:55:01 C117-BS1-01 CRON[37948]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 20:57:06 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 20:57:07 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 21:00:01 C117-BS1-01 CRON[48667]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 21:00:01 C117-BS1-01 CRON[48665]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 21:01:38 C117-BS1-01 dnsmasq-dhcp[11797]: DHCPREQUEST(ns-a89adf00-14) 192.168.1.20 fa:16:3e:72:87:f1
>>> Dec 16 21:01:38 C117-BS1-01 dnsmasq-dhcp[11797]: DHCPACK(ns-a89adf00-14) 192.168.1.20 fa:16:3e:72:87:f1 host-192-168-1-20
>>> Dec 16 21:01:38 C117-BS1-01 dnsmasq-dhcp[11797]: Ignoring duplicate dhcp-option 26
>>> Dec 16 21:02:04 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 21:02:05 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 21:05:01 C117-BS1-01 CRON[58508]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 21:05:01 C117-BS1-01 CRON[58506]: (CRON) info (No MTA installed, discarding output)
>>> Dec 16 21:07:50 C117-BS1-01 systemd[1]: Reloading.
>>> Dec 16 21:07:51 C117-BS1-01 systemd[1]: message repeated 3 times: [ Reloading.]
>>> Dec 16 21:10:01 C117-BS1-01 CRON[3325]: (root) CMD (/usr/local/lib/nagios/plugins/check_netns.sh > /var/lib/nagios/netns-check.txt)
>>> Dec 16 21:10:01 C117-BS1-01 CRON[3323]: (CRON) info (No MTA installed, discarding output)
>>> 
>>>> Am 14.12.2018 um 23:18 schrieb Ben Pfaff <blp at ovn.org <mailto:blp at ovn.org>>:
>>>> 
>>>> Thanks for the report.
>>>> 
>>>> It's difficult to get much from this report because it does not include
>>>> any of the information from OVS itself.  Can you provide OVS logs?  Is
>>>> OVS leaving core dumps?  (Can you provide backtraces?)
>>>> 
>>>> OVS 2.10.1 has been released with many bug fixes over 2.10.0.  Probably
>>>> it's best to try the newer version.
>>>> 
>>>> OVS is normally installed so that it automatically restarts itself if it
>>>> dies.  It sounds like it is not installed that way in your deployment.
> 

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openvswitch.org/pipermail/ovs-discuss/attachments/20181217/6cc01b7e/attachment-0002.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: _usr_lib_openvswitch-switch_ovs-vswitchd.0.crash
Type: application/octet-stream
Size: 1933448 bytes
Desc: not available
URL: <http://mail.openvswitch.org/pipermail/ovs-discuss/attachments/20181217/6cc01b7e/attachment-0001.obj>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openvswitch.org/pipermail/ovs-discuss/attachments/20181217/6cc01b7e/attachment-0003.html>


More information about the discuss mailing list