acassen / keepalived

Keepalived
https://www.keepalived.org
GNU General Public License v2.0
3.96k stars 737 forks source link

Keepalived_vrrp exited due to segmentation fault (SIGSEGV) #1987

Closed drivera-armedia closed 3 years ago

drivera-armedia commented 3 years ago

Describe the bug Nature unknown, reporting as directed due to log message

To Reproduce Unknown.

Expected behavior Keepalived VRRP child process not segfault...?

Keepalived version

Keepalived v2.0.10 (11/12,2018)

Copyright(C) 2001-2018 Alexandre Cassen, <acassen@gmail.com>

Built with kernel headers for Linux 4.18.10
Running on Linux 5.10.60-v7l+ #1449 SMP Wed Aug 25 15:00:44 BST 2021

configure options: --build=arm-linux-gnueabihf --prefix=/usr --includedir=${prefix}/include --mandir=${prefix}/share/man --infodir=${prefix}/share/info --sysconfdir=/etc --localstatedir=/var --disable-silent-rules --libdir=${prefix}/lib/arm-linux-gnueabihf --libexecdir=${prefix}/lib/arm-linux-gnueabihf --runstatedir=/run --disable-maintainer-mode --disable-dependency-tracking --with-kernel-dir=debian/ --enable-snmp --enable-sha1 --enable-snmp-rfcv2 --enable-snmp-rfcv3 --enable-dbus --enable-dbus-create-instance --enable-json --enable-bfd build_alias=arm-linux-gnueabihf CFLAGS=-g -O2 -fdebug-prefix-map=/build/keepalived-17NxHx/keepalived-2.0.10=. -fstack-protector-strong -Wformat -Werror=format-security LDFLAGS=-Wl,-z,relro CPPFLAGS=-Wdate-time -D_FORTIFY_SOURCE=2

Config options:  LIBIPSET_DYNAMIC LVS VRRP VRRP_AUTH JSON BFD OLD_CHKSUM_COMPAT FIB_ROUTING SNMP_V3_FOR_V2 SNMP_VRRP SNMP_CHECKER SNMP_RFCV2 SNMP_RFCV3 DBUS DBUS_CREATE_INSTANCE

System options:  PIPE2 SIGNALFD INOTIFY_INIT1 VSYSLOG EPOLL_CREATE1 IPV4_DEVCONF LIBNL3 RTA_ENCAP RTA_EXPIRES RTA_NEWDST RTA_PREF FRA_SUPPRESS_PREFIXLEN FRA_SUPPRESS_IFGROUP FRA_TUN_ID RTAX_CC_ALGO RTAX_QUICKACK RTEXT_FILTER_SKIP_STATS FRA_L3MDEV FRA_UID_RANGE RTAX_FASTOPEN_NO_COOKIE RTA_VIA FRA_OIFNAME FRA_PROTOCOL FRA_IP_PROTO FRA_SPORT_RANGE FRA_DPORT_RANGE RTA_TTL_PROPAGATE IFA_FLAGS IP_MULTICAST_ALL LWTUNNEL_ENCAP_MPLS LWTUNNEL_ENCAP_ILA LIBIPTC LIBIPSET_PRE_V7 LIBIPVS_NETLINK IPVS_DEST_ATTR_ADDR_FAMILY IPVS_SYNCD_ATTRIBUTES IPVS_64BIT_STATS VRRP_VMAC SOCK_NONBLOCK SOCK_CLOEXEC O_PATH GLOB_BRACE INET6_ADDR_GEN_MODE VRF SO_MARK SCHED_RT SCHED_RESET_ON_FORK

Distro (please complete the following information):

Details of any containerisation or hosted service (e.g. AWS) N/A

Configuration file:

! Configuration File for keepalived

global_defs {
    # delay for second set of gratuitous ARPs after transition to MASTER
    # seconds, default 5, 0 for no second set
    vrrp_garp_master_delay 10

    # delay for second set of gratuitous ARPs after lower priority advert received when MASTER
    vrrp_garp_lower_prio_delay 10

    # number of gratuitous ARP messages to send at a time after lower priority advert received when MASTER
    vrrp_garp_lower_prio_repeat 1

    # minimum time interval for refreshing gratuitous ARPs while MASTER
    # secs, default 0 (no refreshing)
    vrrp_garp_master_refresh 60

    # Enable script security
    enable_script_security

    # Ensure we use unicast, and that only our peers are acceptable
    vrrp_check_unicast_src

    script_user root
}

vrrp_script chk_docker {
    # Look for running Docker processes
    script "/usr/local/bin/docker-ping"

    # every 2 seconds
    interval 2

    # add points in intervals of 2
    weight 2

    # run as the docker user
    user docker
}

vrrp_instance primary_instance {
    # interface to monitor
    interface eth0

    # MASTER or BACKUP
    state BACKUP

    # Multicast source IP
    @dns1 unicast_src_ip 192.168.3.253
    @dns2 unicast_src_ip 192.168.3.252

    # to spread the load even numbers should be on 002 and odd numbers on 001
    @dns1 virtual_router_id 101
    @dns2 virtual_router_id 102

    # the lower the number the higher priority. This should be the number in the hostname
    priority 100

    # Avoid snatching the master role away
    nopreempt

    # virtual ip addresses, one per line, no separators
    virtual_ipaddress {
        192.168.2.254/22
    }

    unicast_peer {
        @dns1 192.168.3.252/22
        @dns2 192.168.3.253/22
    }

    track_script {
        chk_docker
    }

    notify /keepalived.tracker
}

Notify and track scripts

#!/bin/bash
#
# Keepalived Notify Script
#
TYPE="${1}"
NAME="${2}"
STATE="${3}"
shift 3

[ ${#} -gt 0 ] && REST=" (${@})"

exec /usr/bin/logger --tag "keepalived" -s "Transitioning ${TYPE} ${NAME} to ${STATE}${REST}"
#!/bin/bash
#
# Keepalived track script
#
exec /usr/bin/setsid -fw /usr/bin/docker info

System Log entries

# keepalived --dont-fork -lDP
Tue Sep  7 12:59:39 2021: Starting Keepalived v2.0.10 (11/12,2018)
Tue Sep  7 12:59:39 2021: Running on Linux 5.10.60-v7l+ #1449 SMP Wed Aug 25 15:00:44 BST 2021 (built for Linux 4.18.10)
Tue Sep  7 12:59:39 2021: Command line: 'keepalived' '--dont-fork' '-lDP'
Tue Sep  7 12:59:39 2021: Opening file '/etc/keepalived/keepalived.conf'.
Tue Sep  7 12:59:39 2021: Starting VRRP child process, pid=8991
Tue Sep  7 12:59:39 2021: Registering Kernel netlink reflector
Tue Sep  7 12:59:39 2021: Registering Kernel netlink command channel
Tue Sep  7 12:59:39 2021: Opening file '/etc/keepalived/keepalived.conf'.
Tue Sep  7 12:59:39 2021: Assigned address 192.168.3.253 for interface eth0
Tue Sep  7 12:59:39 2021: Registering gratuitous ARP shared channel
Tue Sep  7 12:59:39 2021: (primary_instance) removing VIPs.
Tue Sep  7 12:59:39 2021: (primary_instance) Entering BACKUP STATE (init)
Tue Sep  7 12:59:39 2021: VRRP sockpool: [ifindex(2), family(IPv4), proto(112), unicast(1), fd(11,12)]
Tue Sep  7 12:59:39 2021: Script `chk_docker` now returning 1
Tue Sep  7 12:59:39 2021: VRRP_Script(chk_docker) failed (exited with status 1)
Tue Sep  7 12:59:42 2021: (primary_instance) Receive advertisement timeout
Tue Sep  7 12:59:42 2021: (primary_instance) Entering MASTER STATE
Tue Sep  7 12:59:42 2021: (primary_instance) setting VIPs.
Tue Sep  7 12:59:42 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 12:59:42 2021: (primary_instance) Sending/queueing gratuitous ARPs on eth0 for 192.168.2.254
Tue Sep  7 12:59:42 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 12:59:42 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 12:59:42 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 12:59:42 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 12:59:52 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 12:59:52 2021: (primary_instance) Sending/queueing gratuitous ARPs on eth0 for 192.168.2.254
Tue Sep  7 12:59:52 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 12:59:52 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 12:59:52 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 12:59:52 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 13:00:41 2021: Track script chk_docker is already running, expect idle - skipping run
Tue Sep  7 13:00:41 2021: Interface vethca17c3e added
Tue Sep  7 13:00:41 2021: Interface veth2fd2b67 added
Tue Sep  7 13:00:42 2021: Interface vethca17c3e deleted
Tue Sep  7 13:00:42 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 13:00:42 2021: (primary_instance) Sending/queueing gratuitous ARPs on eth0 for 192.168.2.254
Tue Sep  7 13:00:45 2021: Track script chk_docker is being timed out, expect idle - skipping run
Tue Sep  7 13:00:45 2021: Child (PID 10090) failed to terminate after kill
Tue Sep  7 13:00:45 2021: Child (PID 9844) failed to terminate after kill
Tue Sep  7 13:00:49 2021: Track script chk_docker is already running, expect idle - skipping run
Tue Sep  7 13:00:53 2021: Track script chk_docker is being timed out, expect idle - skipping run
Tue Sep  7 13:00:53 2021: Child (PID 10123) failed to terminate after kill
Tue Sep  7 13:00:53 2021: Child (PID 10109) failed to terminate after kill
Tue Sep  7 13:00:57 2021: Track script chk_docker is already running, expect idle - skipping run
Tue Sep  7 13:00:57 2021: Keepalived_vrrp exited due to segmentation fault (SIGSEGV).
Tue Sep  7 13:00:57 2021:   Please report a bug at https://github.com/acassen/keepalived/issues
Tue Sep  7 13:00:57 2021:   and include this log from when keepalived started, a description
Tue Sep  7 13:00:57 2021:   of what happened before the crash, your configuration file and the details below.
Tue Sep  7 13:00:57 2021:   Also provide the output of keepalived -v, what Linux distro and version
Tue Sep  7 13:00:57 2021:   you are running on, and whether keepalived is being run in a container or VM.
Tue Sep  7 13:00:57 2021:   A failure to provide all this information may mean the crash cannot be investigated.
Tue Sep  7 13:00:57 2021:   If you are able to provide a stack backtrace with gdb that would really help.
Tue Sep  7 13:00:57 2021:   Source version 2.0.10 
Tue Sep  7 13:00:57 2021:   Built with kernel headers for Linux 4.18.10
Tue Sep  7 13:00:57 2021:   Running on Linux 5.10.60-v7l+ #1449 SMP Wed Aug 25 15:00:44 BST 2021
Tue Sep  7 13:00:57 2021:   Command line: 'keepalived' '--dont-fork' '-lDP'
Tue Sep  7 13:00:57 2021:   configure options: --build=arm-linux-gnueabihf --prefix=/usr --includedir=${prefix}/include
Tue Sep  7 13:00:57 2021:                      --mandir=${prefix}/share/man --infodir=${prefix}/share/info --sysconfdir=/etc
Tue Sep  7 13:00:57 2021:                      --localstatedir=/var --disable-silent-rules
Tue Sep  7 13:00:57 2021:                      --libdir=${prefix}/lib/arm-linux-gnueabihf
Tue Sep  7 13:00:57 2021:                      --libexecdir=${prefix}/lib/arm-linux-gnueabihf --runstatedir=/run
Tue Sep  7 13:00:57 2021:                      --disable-maintainer-mode --disable-dependency-tracking --with-kernel-dir=debian/
Tue Sep  7 13:00:57 2021:                      --enable-snmp --enable-sha1 --enable-snmp-rfcv2 --enable-snmp-rfcv3 --enable-dbus
Tue Sep  7 13:00:57 2021:                      --enable-dbus-create-instance --enable-json --enable-bfd
Tue Sep  7 13:00:57 2021:                      build_alias=arm-linux-gnueabihf CFLAGS=-g -O2
Tue Sep  7 13:00:57 2021:                      -fdebug-prefix-map=/build/keepalived-17NxHx/keepalived-2.0.10=.
Tue Sep  7 13:00:57 2021:                      -fstack-protector-strong -Wformat -Werror=format-security LDFLAGS=-Wl,-z,relro
Tue Sep  7 13:00:57 2021:                      CPPFLAGS=-Wdate-time -D_FORTIFY_SOURCE=2
Tue Sep  7 13:00:57 2021:   Config options: LIBIPSET_DYNAMIC LVS VRRP VRRP_AUTH JSON BFD OLD_CHKSUM_COMPAT FIB_ROUTING
Tue Sep  7 13:00:57 2021:                   SNMP_V3_FOR_V2 SNMP_VRRP SNMP_CHECKER SNMP_RFCV2 SNMP_RFCV3 DBUS DBUS_CREATE_INSTANCE
Tue Sep  7 13:00:57 2021:   System options: PIPE2 SIGNALFD INOTIFY_INIT1 VSYSLOG EPOLL_CREATE1 IPV4_DEVCONF LIBNL3 RTA_ENCAP
Tue Sep  7 13:00:57 2021:                   RTA_EXPIRES RTA_NEWDST RTA_PREF FRA_SUPPRESS_PREFIXLEN FRA_SUPPRESS_IFGROUP FRA_TUN_ID
Tue Sep  7 13:00:57 2021:                   RTAX_CC_ALGO RTAX_QUICKACK RTEXT_FILTER_SKIP_STATS FRA_L3MDEV FRA_UID_RANGE
Tue Sep  7 13:00:57 2021:                   RTAX_FASTOPEN_NO_COOKIE RTA_VIA FRA_OIFNAME FRA_PROTOCOL FRA_IP_PROTO FRA_SPORT_RANGE
Tue Sep  7 13:00:57 2021:                   FRA_DPORT_RANGE RTA_TTL_PROPAGATE IFA_FLAGS IP_MULTICAST_ALL LWTUNNEL_ENCAP_MPLS
Tue Sep  7 13:00:57 2021:                   LWTUNNEL_ENCAP_ILA LIBIPTC LIBIPSET_PRE_V7 LIBIPVS_NETLINK IPVS_DEST_ATTR_ADDR_FAMILY
Tue Sep  7 13:00:57 2021:                   IPVS_SYNCD_ATTRIBUTES IPVS_64BIT_STATS VRRP_VMAC SOCK_NONBLOCK SOCK_CLOEXEC O_PATH
Tue Sep  7 13:00:57 2021:                   GLOB_BRACE INET6_ADDR_GEN_MODE VRF SO_MARK SCHED_RT SCHED_RESET_ON_FORK
Tue Sep  7 13:00:57 2021: VRRP child process(8991) died: Respawning
Tue Sep  7 13:00:57 2021: Starting VRRP child process, pid=10148
Tue Sep  7 13:00:57 2021: Registering Kernel netlink reflector
Tue Sep  7 13:00:57 2021: Registering Kernel netlink command channel
Tue Sep  7 13:00:57 2021: Opening file '/etc/keepalived/keepalived.conf'.
Tue Sep  7 13:00:57 2021: Assigned address 192.168.3.253 for interface eth0
Tue Sep  7 13:00:57 2021: Registering gratuitous ARP shared channel
Tue Sep  7 13:00:57 2021: (primary_instance) removing VIPs.
Tue Sep  7 13:00:57 2021: (primary_instance) Entering BACKUP STATE (init)
Tue Sep  7 13:00:57 2021: VRRP sockpool: [ifindex(2), family(IPv4), proto(112), unicast(1), fd(11,12)]
Tue Sep  7 13:00:59 2021: Track script chk_docker is already running, expect idle - skipping run
Tue Sep  7 13:00:59 2021: VRRP_Script(chk_docker) timed_out
Tue Sep  7 13:01:00 2021: (primary_instance) Receive advertisement timeout
Tue Sep  7 13:01:00 2021: (primary_instance) Entering MASTER STATE
Tue Sep  7 13:01:00 2021: (primary_instance) setting VIPs.
Tue Sep  7 13:01:00 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 13:01:00 2021: (primary_instance) Sending/queueing gratuitous ARPs on eth0 for 192.168.2.254
Tue Sep  7 13:01:00 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 13:01:00 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 13:01:00 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 13:01:00 2021: Sending gratuitous ARP on eth0 for 192.168.2.254
Tue Sep  7 13:01:01 2021: VRRP_Script(chk_docker) succeeded
Tue Sep  7 13:01:01 2021: (primary_instance) Changing effective priority from 100 to 102

Did keepalived coredump?

N/A

Additional context

Other interesting behavior is that keepalived is not detecting the peer and both are assuming the role of master, regardless of what I try. I've modified the firewall rules and can see the VRRP traffic being exchanged, and I've also tried flat out disabling the firewall, but they refuse to assume a master-backup stance and both insist on becoming masters.

drivera-armedia commented 3 years ago

All this said, we definitely need a feature where we can up the logging and see if the Keepalived process is even receiving or reacting to any VRRP traffic (and how)...

pqarmitage commented 3 years ago

@drivera-armedia You state: Other interesting behavior is that keepalived is not detecting the peer and both are assuming the role of master, regardless of what I try.

The reason for this is the following configuration snippet:

    @dns1 virtual_router_id 101
    @dns2 virtual_router_id 102

If you want VRRP instances to communicate with each other, they must have the same virtual_router_id (VRID). The purpose of the VRID is to allow independent groups of VRRP instances to operate over the same interfaces.

Replace the above two lines with: virtual_router_id 101 and they should start talking to each other.

You also need to change the priority setting, so that the one you prefer to be master has the higher priority, e.g.

    @dns1 priority 150
    @dns2 priority 100

state BACKUP is unnecessary, so you could remove it.

The unicast_peer block

    unicast_peer {
        @dns1 192.168.3.252/22
        @dns2 192.168.3.253/22
    }

should be changed to:

    unicast_peer {
        @dns1 192.168.3.252
        @dns2 192.168.3.253
    }

since you are not specifying networks, but rather individual IP addresses.

None of the above relates to the segfault you have experienced, but it will enable your two systems to communicate with each other, so that one is MASTER and the other BACKUP.

I'll look further at what might be causing the segfault, but it is worrying that the chk_docker script appears to not be completing, and keepalived is reporting it as still running. I will look into this further, but I though you might find it useful to know about the configuration issues.

drivera-armedia commented 3 years ago

Thank you for those clarifications. The main concern remains the child track_script instance hanging as defunct ... I tried calling docker directly, and only resorted to setsid as an attempt to facilitate child reaping ... no dice!

drivera-armedia commented 3 years ago

I resorted to systemd dependency trickery to get what I wanted (the server to not service the shared IP when docker wasn't running). I would have much preferred to have it happen via "normal" means (i.e. track_script).

I realize this is probably a fairly old version (2.0.10), but I'm surprised it's having such problems with child reaping ... perhaps the timeout is a bit tight? (I'm using the default)

pqarmitage commented 3 years ago

The log messages

Tue Sep  7 13:00:45 2021: Track script chk_docker is being timed out, expect idle - skipping run
Tue Sep  7 13:00:45 2021: Child (PID 10090) failed to terminate after kill
Tue Sep  7 13:00:45 2021: Child (PID 9844) failed to terminate after kill
Tue Sep  7 13:00:49 2021: Track script chk_docker is already running, expect idle - skipping run
Tue Sep  7 13:00:53 2021: Track script chk_docker is being timed out, expect idle - skipping run
Tue Sep  7 13:00:53 2021: Child (PID 10123) failed to terminate after kill
Tue Sep  7 13:00:53 2021: Child (PID 10109) failed to terminate after kill
Tue Sep  7 13:00:57 2021: Track script chk_docker is already running, expect idle - skipping run

appear to be the trigger of the problem. It seems that the /usr/bin/docker info command is not completing and then keepalived is not properly handling the failure of the docker info command to terminate.

Unfortunately I cannot remember if there have been any commits since v2.0.10 relating to fixing scripts failing to terminate (there have been almost 1600 commits in the nearly 3 years since v2.0.10 was released).

If you have a coredump from the segfault, and can provide a symbolic stack backtrace (using gdb) from the coredump, then we might be able to find the cause of the problem. Alternatively can you build keepalived v2.2.4 and try using that to see if you still get the segfault.

I have no experience of using docker, but I have tried running docker info and that appears to start dockerd if it is not running, so I am not clear what is the purpose of the docker-ping script.

I have some Raspberry Pis running 32 bit kernels which appear to match all the software versions you have indicated. I could therefore attempt to reproduce what you are doing, but I would need to know the docker setup and what docker workload you are running.

Are you running on a Raspberry Pi? If so, it would be useful to know what Raspberry Pi model you are using, so that I can try to test on the same model (I have a variety of Raspberry Pi models).

drivera-armedia commented 3 years ago

On systems using Systemd there's a docker.socket unit that gets activated such that if anyone accesses the docker socket the daemon gets started if it's not up already. By disabling this docker can only be brought up or down explicitly which is what I've done. So by doing "docker info" I can test whether docker is running or not, and by disabling docker.socket that won't cause the service to get started by systemd.

I'll try to gather a coredump for you today.

pqarmitage commented 3 years ago

It would be good to see the core dump stacktrace so that we can make sure that the segfault doesn't still exist.

An alternative that some people use to check whether a process is running is: killall -0 dockerd

A better alternative, that doesn't involve having to make periodic checks, is to use track_process. This monitors processes starting and stopping, and so as soon as a process, such as dockerd terminates, then any monitoring vrrp instances will go to fault state, or change their priority, depending on how it is configured. Unfortunately I didn't add track_process until after v2.0.10 so to use track_process your would need to build a later version of keepalived.

pqarmitage commented 3 years ago

The cause of the messages

Track script chk_docker is being timed out, expect idle - skipping run
Child (PID 10090) failed to terminate after kill

were fixed by keepalived v2.0.21.

Can you upgrade keepalived to at least v2.0.21, or better still v2.2.4, and see it that resolves your problem.

drivera-armedia commented 3 years ago

I'm trying to avoid recompiling. For now I've modified the healthcheck scripts to not use docker info as the means for health checks, and things seem to be running smoothly.

Those boxes are due to be upgraded to the latest Debian soon, so hopefully the new repos have updated packages.

Thanks!