Merge pull request #5446 from c-po/dhcp-static-route-flakiness

static: T9278: reconcile FRR config after every DHCP lease event

8 files changed, 70 insertions, 38 deletions

diff --git a/src/conf_mode/protocols_static.py b/src/conf_mode/protocols_static.py
index 0f3f735a7..7d2b4949e 100755
--- a/src/conf_mode/protocols_static.py
+++ b/src/conf_mode/protocols_static.py
@@ -24,6 +24,7 @@ from vyos.configverify import has_frr_protocol_in_dict
 from vyos.configverify import verify_common_route_maps
 from vyos.configverify import verify_vrf
 from vyos.frrender import FRRender
+from vyos.frrender import get_dhcp_route_interfaces
 from vyos.frrender import get_frrender_dict
 from vyos.utils.dict import dict_search
 from vyos.utils.file import write_file
@@ -99,15 +100,11 @@ def generate(config_dict):
     static = vrf and dict_search(f'vrf.name.{vrf}.protocols.static',
                                  config_dict) or config_dict['static']
 
-    # Collect interfaces that have DHCP configuration for DHCP hooks
-    dhcp_interfaces = set()
-
-    # Check for DHCP interfaces in route configurations
-    if 'route' in static:
-        for prefix, prefix_options in static['route'].items():
-            if 'dhcp_interface' in prefix_options:
-                for interface_name in prefix_options['dhcp_interface']:
-                    dhcp_interfaces.add(interface_name)
+    # Collect interfaces that have DHCP configuration for DHCP hooks. This must
+    # be derived from the entire config_dict and not from the (possibly
+    # VRF-narrowed) static dict above, as DHCP_HOOK_IFLIST is a single global
+    # file - a per VRF invocation would otherwise clobber the list.
+    dhcp_interfaces = get_dhcp_route_interfaces(config_dict)
 
     # Write the interface list for DHCP hooks or clean up if empty
     if dhcp_interfaces:
diff --git a/src/etc/dhcp/dhclient-enter-hooks.d/01-vyos-logging b/src/etc/dhcp/dhclient-enter-hooks.d/01-vyos-logging
index 121fb21be..01dd5f496 100644
--- a/src/etc/dhcp/dhclient-enter-hooks.d/01-vyos-logging
+++ b/src/etc/dhcp/dhclient-enter-hooks.d/01-vyos-logging
@@ -3,18 +3,39 @@ LOG_ENABLE="yes"
 LOG_STDERR="no"
 LOG_TAG="dhclient-script-vyos"
 
+# Tracing the individual steps of a lease event is only of interest while
+# debugging - it is silenced unless this flag file exists. Keep in sync with
+# "dhclient_debug_enable" in python/vyos/defaults.py, the file is created by
+# src/init/vyos-router when "vyos-debug" is present on the kernel command line.
+LOG_DEBUG_ENABLE="/tmp/vyos.dhclient.debug"
+
 function logmsg () {
     # log message to journal
-    case $1 in
+    local LOG_PRIO
+    local LOG_LEVEL=$1
+    shift
+
+    case ${LOG_LEVEL} in
+        debug)
+            # Do not even build the message when debugging is not requested
+            if [ ! -f "${LOG_DEBUG_ENABLE}" ] ; then
+                return 0
+            fi
+            LOG_PRIO="daemon.debug" ;;
+        info)  LOG_PRIO="daemon.info" ;;
+        warn)  LOG_PRIO="daemon.warning" ;;
         error) LOG_PRIO="daemon.err" ;;
-        info) LOG_PRIO="daemon.info" ;;
+        *)
+            # Unknown level - do not lose the message, it was never a level
+            LOG_PRIO="daemon.info"
+            set -- "${LOG_LEVEL}" "$@" ;;
     esac
 
     if [ "${LOG_ENABLE}" == "yes" ] ; then
         if [ "${LOG_STDERR}" == "yes" ] ; then
-            /usr/bin/logger -e --id=$$ -s -p ${LOG_PRIO} -t ${LOG_TAG} "${@:2}"
+            /usr/bin/logger -e --id=$$ -s -p ${LOG_PRIO} -t ${LOG_TAG} "$@"
         else
-            /usr/bin/logger -e --id=$$ -p ${LOG_PRIO} -t ${LOG_TAG} "${@:2}"
+            /usr/bin/logger -e --id=$$ -p ${LOG_PRIO} -t ${LOG_TAG} "$@"
         fi
     fi
 }
diff --git a/src/etc/dhcp/dhclient-enter-hooks.d/02-vyos-stopdhclient b/src/etc/dhcp/dhclient-enter-hooks.d/02-vyos-stopdhclient
index ae6bf9f16..2e92c0318 100644
--- a/src/etc/dhcp/dhclient-enter-hooks.d/02-vyos-stopdhclient
+++ b/src/etc/dhcp/dhclient-enter-hooks.d/02-vyos-stopdhclient
@@ -17,7 +17,7 @@ if [ -z ${CONTROLLED_STOP} ] ; then
         dhclients_pids=(`ps --no-headers --format pid,args -C dhclient | awk "{ if(match(\\$0, /\s${interface}(\s|$)/) && !match(\\$0, /\s-6\s/)) printf(\"%s\n\", \\$1) }"`)
     fi
 
-    logmsg info "Current dhclient PID: $current_dhclient, Parent PID: $master_dhclient, IP version: $ipversion_arg, All dhclients for interface $interface: ${dhclients_pids[@]}"
+    logmsg debug "Current dhclient PID: $current_dhclient, Parent PID: $master_dhclient, IP version: $ipversion_arg, All dhclients for interface $interface: ${dhclients_pids[@]}"
     # stop all dhclients for current interface, except current one
     for dhclient in ${dhclients_pids[@]}; do
         if ([ $dhclient -ne $current_dhclient ] && [ $dhclient -ne $master_dhclient ]); then
diff --git a/src/etc/dhcp/dhclient-enter-hooks.d/03-vyos-ipwrapper b/src/etc/dhcp/dhclient-enter-hooks.d/03-vyos-ipwrapper
index bd111d282..83dc16276 100644
--- a/src/etc/dhcp/dhclient-enter-hooks.d/03-vyos-ipwrapper
+++ b/src/etc/dhcp/dhclient-enter-hooks.d/03-vyos-ipwrapper
@@ -19,7 +19,7 @@ VRF_OPTION=$(/usr/sbin/ip --json --detail link show ${interface} | jq -r '.[0] |
 _flush_dhcp_addrs() {
     local dev="${1:-$interface}"
 
-    logmsg info "Selectively flushing only dynamic (DHCP) addresses from ${dev}"
+    logmsg debug "Selectively flushing only dynamic (DHCP) addresses from ${dev}"
 
     local addrs
     addrs=$(/usr/sbin/ip -4 -j addr show dev "${dev}" 2>&1 | jq -r '
@@ -47,10 +47,10 @@ _flush_dhcp_addrs() {
 function frr_alive () {
     /usr/lib/frr/watchfrr.sh all_status
     if [ "$?" -eq "0" ] ; then
-        logmsg info "FRR status: running"
+        logmsg debug "FRR status: running"
         return 0
     else
-        logmsg info "FRR status: not running"
+        logmsg debug "FRR status: not running"
         return 1
     fi
 }
@@ -97,15 +97,29 @@ function iptovtysh () {
     if [ "$VTYSH_ACTION" == "del" ] ; then
         VTYSH_CMD="no $VTYSH_CMD"
     fi
-    logmsg info "Converted vtysh command: \"$VTYSH_CMD\""
+    logmsg debug "Converted vtysh command: \"$VTYSH_CMD\""
+}
+
+# Return the VRF option for a command, unless the caller already specified one.
+# 01-vyos-cleanup builds its "ip route del" with an explicit "vrf <name>", and
+# appending $VRF_OPTION on top of that produced "vrf red vrf red".
+function vrf_option () {
+    local arg
+    for arg in "$@" ; do
+        if [ "$arg" == "vrf" ] ; then
+            return 0
+        fi
+    done
+    echo "$VRF_OPTION"
 }
 
 # delete the same route from kernel before adding new one
 function delroute () {
-    logmsg info "Checking if the route presented in kernel: $@ $VRF_OPTION"
-    if /usr/sbin/ip route show $@ $VRF_OPTION | grep -qx "$1 " ; then
-        logmsg info "Deleting IP route: \"/usr/sbin/ip route del $@ $VRF_OPTION\""
-        /usr/sbin/ip route del $@ $VRF_OPTION
+    local VRF_ARG=$(vrf_option "$@")
+    logmsg debug "Checking if the route presented in kernel: $@ $VRF_ARG"
+    if /usr/sbin/ip route show $@ $VRF_ARG | grep -qx "$1 " ; then
+        logmsg info "Deleting IP route: \"/usr/sbin/ip route del $@ $VRF_ARG\""
+        /usr/sbin/ip route del $@ $VRF_ARG
     fi
 }
 
@@ -114,10 +128,10 @@ function vtysh_conf () {
     # perform 10 attempts with 1 second delay for retries
     for i in {1..10} ; do
         if vtysh  -c "conf t" -c "$1" ; then
-            logmsg info "Command was executed successfully via vtysh: \"$1\""
+            logmsg debug "Command was executed successfully via vtysh: \"$1\""
             return 0
         else
-            logmsg info "Failed to send command to vtysh, retrying in 1 second"
+            logmsg warn "Failed to send command to vtysh, retrying in 1 second"
             sleep 1
         fi
     done
@@ -130,7 +144,7 @@ function ip () {
     # Intercept: ip -4 addr flush dev <interface>
     # to preserve static addresses (only remove dynamic/DHCP addresses)
     if [ "$1" = "-4" ] && [ "$2" = "addr" ] && [ "$3" = "flush" ]; then
-        logmsg info "Intercepting 'ip -4 addr flush' to preserve static addresses"
+        logmsg debug "Intercepting 'ip -4 addr flush' to preserve static addresses"
         shift 3
         local dev=""
         while [ $# -gt 0 ]; do
@@ -143,19 +157,19 @@ function ip () {
 
     # pass command to system `ip` if this is not related to routes change
     if [ "$2" != "route" ] ; then
-        logmsg info "Passing command to /usr/sbin/ip: \"$@\""
+        logmsg debug "Passing command to /usr/sbin/ip: \"$@\""
         /usr/sbin/ip $@
     else
         # if we want to work with routes, try to use FRR first
         if frr_alive ; then
             delroute ${@:4}
             iptovtysh $@
-            logmsg info "Sending command to vtysh"
+            logmsg debug "Sending command to vtysh"
             vtysh_conf "$VTYSH_CMD"
         else
             # add ip route to kernel
             logmsg info "Modifying routes in kernel: \"/usr/sbin/ip $@\""
-            /usr/sbin/ip $@ $VRF_OPTION
+            /usr/sbin/ip $@ $(vrf_option "$@")
         fi
     fi
 }
diff --git a/src/etc/dhcp/dhclient-enter-hooks.d/04-vyos-resolvconf b/src/etc/dhcp/dhclient-enter-hooks.d/04-vyos-resolvconf
index 9a8a53bfd..9aa3a725c 100644
--- a/src/etc/dhcp/dhclient-enter-hooks.d/04-vyos-resolvconf
+++ b/src/etc/dhcp/dhclient-enter-hooks.d/04-vyos-resolvconf
@@ -23,10 +23,10 @@ if /usr/bin/systemctl -q is-active vyos-hostsd; then
         fi
 
         if [ $hostsd_changes ]; then
-            logmsg info "Applying changes via vyos-hostsd-client"
+            logmsg debug "Applying changes via vyos-hostsd-client"
             $hostsd_client --apply
         else
-            logmsg info "No changes to apply via vyos-hostsd-client"
+            logmsg debug "No changes to apply via vyos-hostsd-client"
         fi
     }
 fi
diff --git a/src/etc/dhcp/dhclient-exit-hooks.d/01-vyos-cleanup b/src/etc/dhcp/dhclient-exit-hooks.d/01-vyos-cleanup
index da1bda137..803940ecc 100644
--- a/src/etc/dhcp/dhclient-exit-hooks.d/01-vyos-cleanup
+++ b/src/etc/dhcp/dhclient-exit-hooks.d/01-vyos-cleanup
@@ -108,8 +108,8 @@ if [[ $reason =~ ^(EXPIRE6|RELEASE6|STOP6)$ ]]; then
 fi
 
 if [ $hostsd_changes ]; then
-    logmsg info "Applying changes via vyos-hostsd-client"
+    logmsg debug "Applying changes via vyos-hostsd-client"
     $hostsd_client --apply
 else
-    logmsg info "No changes to apply via vyos-hostsd-client"
+    logmsg debug "No changes to apply via vyos-hostsd-client"
 fi
diff --git a/src/etc/dhcp/dhclient-exit-hooks.d/98-vyos-static-routes-dhclient-hook b/src/etc/dhcp/dhclient-exit-hooks.d/98-vyos-static-routes-dhclient-hook
index 7038bf25e..4f207411e 100755
--- a/src/etc/dhcp/dhclient-exit-hooks.d/98-vyos-static-routes-dhclient-hook
+++ b/src/etc/dhcp/dhclient-exit-hooks.d/98-vyos-static-routes-dhclient-hook
@@ -14,12 +14,11 @@
 # You should have received a copy of the GNU General Public License
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 
-DHCP_HOOK_IFLIST="/tmp/static_dhcp_interfaces"
-
-# Only run if there are static routes with dhcp-interface configured
-if ! { [ -f $DHCP_HOOK_IFLIST ] && grep -qw $interface $DHCP_HOOK_IFLIST; }; then
-    return 0
-fi
+# The FRR static route configuration embeds the DHCP gateway of an interface,
+# either for "protocols static route <prefix> dhcp-interface <ifname>" or for
+# the default route implied by "interfaces <type> <ifname> address dhcp". The
+# gateway is only known at lease time, so any lease event must reconcile the
+# rendered configuration with the current lease (T8465).
 
 # Re-generate the config on the following events:
 # - BOUND: always re-generate
diff --git a/src/init/vyos-router b/src/init/vyos-router
index 8e0a671a6..8e270602e 100755
--- a/src/init/vyos-router
+++ b/src/init/vyos-router
@@ -590,6 +590,7 @@ start ()
         touch /tmp/vyos.ifconfig.debug
         touch /tmp/vyos.container.debug
         touch /tmp/vyos.smoketest.debug
+        touch /tmp/vyos.dhclient.debug
     fi
 
     # Cleanup PKI CAs