From 141116f5500b21d900a7db3ffcb30249e9adccd1 Mon Sep 17 00:00:00 2001 From: Josh Patterson Date: Thu, 16 Jul 2026 16:52:06 -0400 Subject: [PATCH] Make so-salt-minion-wait work without requiring a restart The wait required both a socket gate and a log gate to pass. The log gate greps the minion log for salt's one-time startup line "Minion is ready to receive requests!", which scrolls out of the log tail on a minion that has not restarted recently. On such a minion the log gate could never pass, so the script ran to its full 120s timeout and exited 1 even though the minion was healthy and connected. This also false-timed-out when salt_minion_service reported a non-restart change (e.g. an enable toggle). The log gate's only remaining purpose is closing the ~2.8s post-connect window where the master sockets are up but _post_master_init() is still loading. Gate it on the current pid's uptime: enforce the ready line only within READY_LINE_WINDOW (90s) of (re)start, and let the already restart-independent socket gate be the steady-state authority past that. The fresh-restart path is unchanged, and if uptime can't be read the strict behavior is kept. --- salt/salt/minion/init.sls | 17 ++++--- salt/salt/tools/sbin/so-salt-minion-wait | 63 ++++++++++++++++++------ 2 files changed, 58 insertions(+), 22 deletions(-) diff --git a/salt/salt/minion/init.sls b/salt/salt/minion/init.sls index 1f1ec8305..fa94ec7be 100644 --- a/salt/salt/minion/init.sls +++ b/salt/salt/minion/init.sls @@ -131,13 +131,16 @@ salt_minion_service: {% endif %} - order: last -# block until the just-restarted salt-minion daemon logs "Minion is ready to receive requests!" -# for the current instance, so follow-on jobs and the next highstate iteration do not race the -# restart. onchanges + require on salt_minion_service catches every restart trigger uniformly -# because watch mod_watch results replace the service state's running entry. wait logic lives in -# /usr/sbin/so-salt-minion-wait (deployed by salt_sbin from salt/tools/sbin/); it keys the ready -# line to the current daemon pid (resolved via systemd, not the pidfile) and corroborates with the -# master req/publish sockets. set_log_levels above enforces the log_level_logfile: info that the +# block until the salt-minion daemon is ready for the current instance, so follow-on jobs and the +# next highstate iteration do not race the restart. onchanges + require on salt_minion_service +# catches every restart trigger uniformly because watch mod_watch results replace the service +# state's running entry. wait logic lives in /usr/sbin/so-salt-minion-wait (deployed by salt_sbin +# from salt/tools/sbin/); its steady-state authority is the master req/publish sockets for the +# current daemon pid (resolved via systemd, not the pidfile), and it corroborates a just-restarted +# instance with the pid-tagged "Minion is ready to receive requests!" log line only within a short +# window of startup. Because that socket signal does not require a recent restart, the wait also +# succeeds cleanly when salt_minion_service reports a non-restart change (e.g. an enable toggle) +# rather than false-timing-out. set_log_levels above enforces the log_level_logfile: info that the # ready line depends on. salt restarts this unit with --no-block, so mod_watch returns while the old # daemon is still up; the script waits for systemd's restart job to drain before it reads MainPID. wait_for_salt_minion_ready: diff --git a/salt/salt/tools/sbin/so-salt-minion-wait b/salt/salt/tools/sbin/so-salt-minion-wait index 984f144f3..cf16ab0d1 100644 --- a/salt/salt/tools/sbin/so-salt-minion-wait +++ b/salt/salt/tools/sbin/so-salt-minion-wait @@ -5,21 +5,29 @@ # https://securityonion.net/license; you may not use this file except in compliance with the # Elastic License 2.0. -# Block until the just-restarted salt-minion daemon reaches the point where salt itself logs -# "Minion is ready to receive requests!". Invoked from the wait_for_salt_minion_ready state in -# salt/minion/init.sls after salt_minion_service fires its watch-driven restart, so follow-on jobs -# and the next highstate iteration do not race it. +# Block until the current salt-minion daemon is ready to receive requests. Invoked from the +# wait_for_salt_minion_ready state in salt/minion/init.sls after salt_minion_service fires its +# watch-driven restart, so follow-on jobs and the next highstate iteration do not race it. It is +# also correct on an already-running minion (no recent restart): the steady-state readiness signal +# is the live master sockets, so it does not depend on a restart having just happened. # -# Salt logs that line from Minion.tune_in() only after sync_connect_master() returns, which means -# the pub channel authenticated, the long-running req channel connected, and _post_master_init() -# finished loading modules and compiling pillar. Two signals reproduce that: +# Salt logs "Minion is ready to receive requests!" from Minion.tune_in() only after +# sync_connect_master() returns, which means the pub channel authenticated, the long-running req +# channel connected, and _post_master_init() finished loading modules and compiling pillar. Two +# signals reproduce that: # -# 1. Primary the pid-tagged ready line in the minion log. Salt's log_fmt_logfile embeds +# 1. Steady state the pid holds an ESTABLISHED req connection to a master on 4506 plus a second +# (publish) connection to that same master IP on another port. The publish port is +# learned from the master's auth reply and is absent from minion config, so it is +# derived from the connection rather than read from config. This is the always-on +# authority: it reflects whatever daemon is running now, restart or not. +# 2. Startup only the pid-tagged ready line in the minion log. Salt's log_fmt_logfile embeds # [%(process)d] just before the message, so this is keyed to one daemon instance. -# 2. Corroborating that same pid holds an ESTABLISHED req connection to a master on 4506 plus a -# second (publish) connection to that same master IP on another port. The publish -# port is learned from the master's auth reply and is absent from minion config, -# so it is derived from the connection rather than read from config. +# Salt logs it exactly once per start, so it exists only to close a ~2.8s window +# after the sockets come up where they are established but _post_master_init() is +# still finishing. It is therefore required only within READY_LINE_WINDOW seconds +# of (re)start (by pid uptime); past that the line has scrolled out of the log and +# the socket gate alone decides. See instance_ready(). # # The daemon pid is resolved from systemd, never from /var/run/salt-minion.pid. salt_minion() runs # the real minion in a multiprocessing child; that child writes the pidfile, owns the sockets and @@ -43,6 +51,12 @@ INITIAL_SLEEP=3 TIMEOUT=120 MASTER_PORT=4506 LOG_TAIL_LINES=10000 +# Seconds after a (re)start during which the pid-tagged ready line is still required. Past this the +# daemon is clearly beyond the ~2.8s post-connect race and the socket gate is authoritative -- the +# one-time ready line has scrolled out of the log tail on a long-running minion. Kept under TIMEOUT +# so a fresh minion that connects but never logs the line still falls back to socket-only near the +# end instead of false-timing-out. +READY_LINE_WINDOW=90 DEFAULT_LOG_FILE="/opt/so/log/salt/minion" LOG_FILE="$DEFAULT_LOG_FILE" @@ -103,6 +117,15 @@ resolve_daemon_pids() { printf '%s\n' "${children:-$mainpid}" } +# Elapsed seconds since this pid started (Linux procps etimes). Empty/non-numeric -> failure, so the +# caller can fall back to the strict (log-gate-enforced) behavior when uptime cannot be read. +pid_uptime() { + local pid=$1 secs + secs=$(ps -o etimes= -p "$pid" 2>/dev/null | tr -d ' ') + case "$secs" in ''|*[!0-9]*) return 1 ;; esac + printf '%s\n' "$secs" +} + # True iff the ready line tagged with this pid is in the current or most recently rotated log. ready_logged() { local pid=$1 f @@ -135,9 +158,19 @@ socket_ready() { } instance_ready() { - local pid=$1 - if [ "$USE_LOG_GATE" -eq 1 ] && ! ready_logged "$pid"; then - return 1 + local pid=$1 uptime + # The log gate only closes the ~2.8s window right after the master sockets come up where they are + # established but _post_master_init() is still loading modules/compiling pillar. Salt logs the + # pid-tagged ready line exactly once at startup, so on a daemon that started long ago the line has + # scrolled out of the log tail and the gate could never pass -- making the wait require a recent + # restart. Enforce it only while the daemon is young enough that the race could still be open; past + # READY_LINE_WINDOW the socket gate is authoritative. If uptime can't be read, keep the strict + # behavior (uptime=0 -> gate enforced) so the fresh-restart path never regresses. + if [ "$USE_LOG_GATE" -eq 1 ]; then + uptime=$(pid_uptime "$pid") || uptime=0 + if [ "$uptime" -lt "$READY_LINE_WINDOW" ] && ! ready_logged "$pid"; then + return 1 + fi fi if [ "$USE_SOCKET_GATE" -eq 1 ] && ! socket_ready "$pid"; then return 1