Merge pull request 'fleetd #552: warn instead of aborting when the post-restart mktemp fails' (#560) from worker/552-post-restart-mktemp-abort-bc2672-4 into main

scripts/redeploy-fleetd.sh

@@ -549,14 +549,51 @@ check_log_path_matches_plist() {
   ok "log path check: script and plist agree ($resolved_out)"
 }
 
+# fleetd #552: the post-restart fresh-log capture, pulled out of the main flow so it is testable by
+# sourcing (the same reason systemd_installed/systemd_loaded above guard their OWN mktemp inline
+# instead of leaving it bare) even though its only caller sits below the SOURCED guard. By the time
+# the caller reaches this, the daemon has already been stopped, the jar swapped, and the new daemon
+# started — fleetd #552's whole point is that a `mktemp` failure here must never undo that success
+# by aborting the script, the way the old unguarded `FRESH_LOG="$(mktemp ...)"` assignment did.
+#
+# So this function never dies, and — like detect_supervisor above — never reports failure through a
+# global either: it is meant to be called as `VAR="$(capture_fresh_log_region ...)"`, which runs it
+# in a subshell, and any global it set there would die with that subshell. Failure crosses back the
+# only way that survives: a non-zero exit and empty stdout. The caller decides what a failure means
+# (warn, and leave FRESH_LOG at its already-declared "" sentinel) and owns the EXIT trap, because
+# that trap has to outlive this function's own return — the file must survive until every reader
+# below (classify_amqp_connection_errors, report_shutdown_drain, the result section) has looked.
+capture_fresh_log_region() {
+  local out_file="$1" restart_mark="$2" log_file
+  if ! log_file="$(mktemp -t fleetd-fresh-log.XXXXXX)"; then
+    return 1
+  fi
+  tail -n "+$((restart_mark + 1))" "$out_file" > "$log_file" 2>/dev/null || true
+  printf '%s' "$log_file"
+}
+
 # Classify ERROR lines in one fresh log region. AMQP failure messages now include the connection
 # name, so a recovery can clear only errors for its own connection. A candidate with neither name
 # remains unexplained: it must never be quieted by a recovery on the other connection.
+#
+# fleetd #552: log_file can now arrive as "" — capture_fresh_log_region's own sentinel for "the
+# post-restart region could never be captured". That is a DIFFERENT fact from "captured a region
+# with nothing in it", which is exactly what every count below staying at its initialized 0 already
+# means; conflating the two would make "no errors found" and "could not look for errors" print
+# identically; the exact defect class this ticket exists to fix. REDEPLOY_AMQP_CHECK_SKIPPED carries
+# the distinction to the result section below, and this reader says so in its own output too.
 classify_amqp_connection_errors() {
   local log_file="$1" line pending_inbox=0 pending_lead_mailbox=0
   REDEPLOY_ERROR_COUNT=0
   REDEPLOY_RECOVERED_AMQP_ERRORS=0
   REDEPLOY_UNEXPLAINED_ERRORS=0
+  REDEPLOY_AMQP_CHECK_SKIPPED=0
+
+  if [ -z "$log_file" ]; then
+    REDEPLOY_AMQP_CHECK_SKIPPED=1
+    warn "cannot check for AMQP/ERROR lines since restart — the post-restart log region could not be captured"
+    return 0
+  fi
 
   while IFS= read -r line || [ -n "$line" ]; do
     case "$line" in
@@ -680,6 +717,19 @@ report_shutdown_drain() {
     return 0
   fi
 
+  # fleetd #552: checked AFTER the n/a case above, not before it — a cold start has nothing to check
+  # regardless of whether the log region could be captured, and that fact must not be overridden by
+  # an unrelated mktemp failure. "skipped" is a fifth state on REDEPLOY_DRAIN_STATE, distinct from
+  # "unknown" (the log WAS read, and neither a drain-complete line nor an exception shape was found
+  # in it): here there was no log to read at all, and that is a different fact that must say so in
+  # its own output, never silently reported as "unknown" or, worse, as "complete"/"n/a".
+  if [ -z "$log_file" ]; then
+    REDEPLOY_DRAIN_STATE="skipped"
+    warn "cannot tell whether the previous daemon's shutdown drain finished — the post-restart log"
+    warn "region could not be captured"
+    return 0
+  fi
+
   find_drain_complete_line "$log_file"
   scan_uncaught_exceptions "$log_file"
 
@@ -1110,9 +1160,24 @@ tail -n "+$((RESTART_MARK + 1))" "$OUT" 2>/dev/null \
 
 # Errors since the restart, anchored to the marker so old noise cannot leak in. Keep the fresh
 # region in a file because the classifier must preserve the order of errors and recoveries.
-FRESH_LOG="$(mktemp -t fleetd-fresh-log.XXXXXX)"
+#
+# fleetd #552: by this point the daemon has already been stopped, the jar swapped, and the new
+# daemon started. The old unguarded `FRESH_LOG="$(mktemp ...)"` here aborted the whole script on any
+# mktemp failure — AFTER all of that had already succeeded — so a caller read the resulting non-zero
+# exit as "the redeploy failed" and the likely next action was to restart an already-correctly-
+# restarted daemon. The mktemp itself now lives in capture_fresh_log_region (guarded the same way
+# :293/:317/:344/:359 guard their own), and a failure there only warns: there is nothing left to
+# protect by refusing after a successful restart. FRESH_LOG="" is declared and the trap installed
+# BEFORE the call that may fail to fill it in, not after — an empty FRESH_LOG makes `rm -f ""` a
+# harmless no-op, so there is no ordering hazard left between "the file might already exist" and
+# "the trap that cleans it up".
+FRESH_LOG=""
 trap 'rm -f "$FRESH_LOG"' EXIT
-tail -n "+$((RESTART_MARK + 1))" "$OUT" > "$FRESH_LOG" 2>/dev/null || true
+if ! FRESH_LOG="$(capture_fresh_log_region "$OUT" "$RESTART_MARK")"; then
+  warn "could not create a temp file for the post-restart log region — the restart itself already"
+  warn "succeeded (pid $NEW_PID); only the post-restart ERROR/drain checks below are skipped."
+  warn "Check $OUT yourself for anything since the restart."
+fi
 classify_amqp_connection_errors "$FRESH_LOG"
 
 # fleetd #512 part 2: the previous daemon's shutdown drain, checked in the same fresh-log region —
@@ -1131,7 +1196,14 @@ assert_single_daemon "$(running_pid)"
 
 say "result"
 ok "pid $NEW_PID, jar $(jar_id)"
-if [ "$REDEPLOY_ERROR_COUNT" -eq 0 ]; then
+if [ "$REDEPLOY_AMQP_CHECK_SKIPPED" -eq 1 ]; then
+  # fleetd #552: the fourth reader of the fresh-log region. Without this branch REDEPLOY_ERROR_COUNT
+  # stays at its untouched 0 (classify_amqp_connection_errors never got a file to read) and
+  # REDEPLOY_DRAIN_STATE is "skipped" (never "complete"/"n/a"), so the branches below would print
+  # NOTHING about ERROR lines at all — a silence that reads exactly like the clean bill of health
+  # this ticket exists to prevent. Say the unknown result out loud instead.
+  warn "ERROR-line count since restart is UNKNOWN — the post-restart log region could not be captured (see above)"
+elif [ "$REDEPLOY_ERROR_COUNT" -eq 0 ]; then
   # fleetd #512 item 4: this line must not print when the shutdown-drain check above found the
   # previous daemon's drain died, or could not tell — either would make "no ERROR lines" read as a
   # clean bill of health it is not (an uncaught exception never carries an ERROR token to begin

scripts/test-redeploy-fleetd.sh

@@ -236,6 +236,129 @@ test_no_unguarded_macos_only_hasher_calls() {
     || fail "script(s) invoke the macOS-only hasher with no portable-hasher-first fallback guard in the same file: $bad"
 }
 
+# fleetd #552 — the shape, not the one line just fixed: a `mktemp` failure AFTER the daemon has
+# already been restarted must never be a bare, unguarded assignment again, anywhere in the script,
+# so the next one added is caught too — not just line 1113 as it stood at 26f380a. Anchored on the
+# real "start" section (the restart call itself), the same anchor test_swap_ordered_after_wait_and_
+# before_start above already uses for "before the start section". Needle built from two concatenated
+# pieces, the same trick test_no_unguarded_macos_only_hasher_calls uses above, so this check's own
+# description of the pattern it looks for can never become a match for itself.
+test_no_unguarded_mktemp_assignments_after_restart() {
+  local src="$ROOT/scripts/redeploy-fleetd.sh" start_line needle bad
+  start_line="$(grep -Fn 'say "start"' "$src" | head -1 | cut -d: -f1 || true)"
+  [ -n "$start_line" ] || fail "could not find the restart call's start section in redeploy-fleetd.sh"
+  needle='^[[:space:]]*[A-Za-z_][A-Za-z0-9_]*="'
+  needle="$needle"'\$\(mktemp'
+  bad="$(grep -nE "$needle" "$src" | awk -F: -v start="$start_line" '$1+0>start')"
+  [ -z "$bad" ] \
+    || fail "unguarded 'VAR=\"\$(mktemp ...)\"' assignment(s) after the restart call (fleetd #552): $bad"
+}
+
+# fleetd #552 — capture_fresh_log_region itself. Sourcing stops before the main flow can be driven
+# directly (the SOURCED guard below), so this exercises the extracted function the real call site
+# now uses, the same stub-mktemp-on-PATH technique
+# test_detect_supervisor_systemd_probe_setup_failure_is_unclear uses above.
+test_capture_fresh_log_region_control() {
+  printf 'line one\nline two\nline three\n' > "$TMP/fresh-log-src.out"
+  local result
+  result="$(capture_fresh_log_region "$TMP/fresh-log-src.out" 0)"
+  [ -n "$result" ] || fail "capture_fresh_log_region returned nothing on a working mktemp"
+  [ -f "$result" ] || fail "capture_fresh_log_region did not create the file it named"
+  assert_equals "$(printf 'line one\nline two\nline three')" "$(cat "$result")" \
+    "captured region did not carry the whole source file (restart_mark=0)"
+  rm -f "$result"
+}
+
+test_capture_fresh_log_region_mktemp_failure_returns_nonzero_and_prints_nothing() {
+  local bin_dir rc=0 out
+  bin_dir="$TMP/stub-bin-fresh-log-mktemp-fails"; mkdir -p "$bin_dir"
+  cat > "$bin_dir/mktemp" <<'STUB'
+#!/usr/bin/env bash
+echo "mktemp: cannot create temp file" >&2
+exit 1
+STUB
+  chmod +x "$bin_dir/mktemp"
+  printf 'line one\n' > "$TMP/fresh-log-src2.out"
+
+  out="$(PATH="$bin_dir:$PATH" capture_fresh_log_region "$TMP/fresh-log-src2.out" 0)" && rc=0 || rc=$?
+  [ "$rc" -ne 0 ] \
+    || fail "capture_fresh_log_region must return non-zero when its own mktemp fails"
+  [ -z "$out" ] \
+    || fail "capture_fresh_log_region printed a path even though mktemp failed: $out"
+}
+
+# fleetd #552 acceptance: "the exit status after a stubbed mktemp failure must still report the
+# restart's own outcome". Sourcing stops before the main flow runs, so this drives the REAL
+# call-site shape (the `if ! FRESH_LOG="$(capture_fresh_log_region ...)"; then warn; fi` guard that
+# now stands where the old unguarded assignment did) in a subshell, under the SAME `set -euo
+# pipefail` the real script runs under, with `mktemp` stubbed to fail on PATH. A regression back to
+# the old unguarded `FRESH_LOG="$(mktemp ...)"` shape would abort this subshell before it reaches
+# SUBSHELL_REACHED_END, and this test would go red with a non-zero rc.
+test_fresh_log_capture_failure_does_not_abort_under_sete() {
+  local bin_dir rc=0 out
+  bin_dir="$TMP/stub-bin-call-site-mktemp-fails"; mkdir -p "$bin_dir"
+  cat > "$bin_dir/mktemp" <<'STUB'
+#!/usr/bin/env bash
+echo "mktemp: cannot create temp file" >&2
+exit 1
+STUB
+  chmod +x "$bin_dir/mktemp"
+  printf 'line one\n' > "$TMP/fresh-log-callsite.out"
+
+  out="$(
+    PATH="$bin_dir:$PATH"
+    set -euo pipefail
+    FRESH_LOG=""
+    trap 'rm -f "$FRESH_LOG"' EXIT
+    if ! FRESH_LOG="$(capture_fresh_log_region "$TMP/fresh-log-callsite.out" 0)"; then
+      echo "WARN skipped"
+    fi
+    echo "SUBSHELL_REACHED_END"
+  )" && rc=0 || rc=$?
+
+  [ "$rc" -eq 0 ] \
+    || fail "the guarded call-site shape aborted under set -e when mktemp failed (rc=$rc) — a successful restart must not be reported as a failure"
+  printf '%s' "$out" | grep -qF 'SUBSHELL_REACHED_END' \
+    || fail "the subshell aborted before reaching the end — a post-restart mktemp failure must not abort the script"
+  printf '%s' "$out" | grep -qF 'WARN skipped' \
+    || fail "the guarded call site did not report the post-restart check as skipped when mktemp failed"
+}
+
+# fleetd #552 item 4 (the fourth reader): the result section must check REDEPLOY_AMQP_CHECK_SKIPPED
+# and say so BEFORE it ever consults REDEPLOY_ERROR_COUNT — otherwise a skipped capture (which
+# leaves REDEPLOY_ERROR_COUNT at its untouched 0) falls through the same "no ERROR lines" gate a
+# genuinely clean restart uses, and (because REDEPLOY_DRAIN_STATE is "skipped", not "complete"/"n/a")
+# prints nothing at all: a silence indistinguishable from the clean bill of health this ticket exists
+# to prevent. Sourcing stops before the main flow runs, so this is a source-text ordering check, the
+# same shape as test_report_shutdown_drain_ordered_after_classify_and_before_result above.
+# fleetd #552 — closes the gap test_no_unguarded_mktemp_assignments_after_restart cannot: after
+# extracting the mktemp into capture_fresh_log_region, the SAME class of hazard (an unguarded
+# command-substitution assignment that can abort the script under set -e, because capture_fresh_
+# log_region still returns non-zero on its own mktemp failure) would reappear if the main flow's
+# call to it ever lost its own "if !" guard — and that line no longer contains the literal text
+# "mktemp", so the sweep above cannot see it. Pin the real call site directly instead, the same
+# shape test_swap_ordered_after_wait_and_before_start above uses for its own call site.
+test_capture_fresh_log_region_call_site_is_guarded() {
+  local src="$ROOT/scripts/redeploy-fleetd.sh" call_line
+  call_line="$(grep -Fn 'if ! FRESH_LOG="$(capture_fresh_log_region "$OUT" "$RESTART_MARK")"; then' "$src" | head -1 | cut -d: -f1 || true)"
+  [ -n "$call_line" ] \
+    || fail "could not find the main flow's guarded capture_fresh_log_region call site in redeploy-fleetd.sh"
+}
+
+test_result_section_checks_amqp_skip_before_no_error_lines() {
+  local src="$ROOT/scripts/redeploy-fleetd.sh" result_line skip_line ok_line
+  result_line="$(grep -Fn 'say "result"' "$src" | head -1 | cut -d: -f1 || true)"
+  skip_line="$(grep -Fn '"$REDEPLOY_AMQP_CHECK_SKIPPED" -eq 1' "$src" | tail -1 | cut -d: -f1 || true)"
+  ok_line="$(grep -Fn 'ok "no ERROR lines since restart"' "$src" | head -1 | cut -d: -f1 || true)"
+  [ -n "$result_line" ] || fail "could not find the result section in redeploy-fleetd.sh"
+  [ -n "$skip_line" ] || fail "could not find a REDEPLOY_AMQP_CHECK_SKIPPED check in redeploy-fleetd.sh"
+  [ -n "$ok_line" ] || fail "could not find the 'no ERROR lines since restart' line in redeploy-fleetd.sh"
+  [ "$skip_line" -gt "$result_line" ] \
+    || fail "the REDEPLOY_AMQP_CHECK_SKIPPED check (line $skip_line) is not inside the result section (starts line $result_line)"
+  [ "$skip_line" -lt "$ok_line" ] \
+    || fail "the REDEPLOY_AMQP_CHECK_SKIPPED check (line $skip_line) is not checked before 'no ERROR lines since restart' (line $ok_line)"
+}
+
 # fleetd #492 follow-up (Item 1): this must go through the REAL call-site shape at :437-440, not a
 # hand-constructed "unclear" value — a test that builds "unclear" directly proves the switch, not
 # the handoff, and that is exactly the gap that let SUPERVISOR_UNCLEAR_DETAIL never reach the real
@@ -890,6 +1013,20 @@ LOG
   classify_fixture no-errors.log
   assert_equals 0 "$REDEPLOY_ERROR_COUNT" "no-errors total"
   assert_equals 0 "$REDEPLOY_UNEXPLAINED_ERRORS" "no-errors unexplained"
+  # fleetd #552 control: a REAL, readable log region with nothing in it must never look like a
+  # region that could not be captured at all.
+  assert_equals 0 "$REDEPLOY_AMQP_CHECK_SKIPPED" "no-errors must not report the check as skipped"
+}
+
+# fleetd #552 — the third state: "" (capture_fresh_log_region's own sentinel for "the post-restart
+# region could never be captured") must never look like "read a file with nothing in it", which is
+# exactly what REDEPLOY_ERROR_COUNT staying at 0 already means on its own (see test_no_errors above).
+test_classify_amqp_connection_errors_reports_skipped_when_log_missing() {
+  classify_amqp_connection_errors "" > "$TMP/classify-skipped-output" 2>&1
+  assert_equals 1 "$REDEPLOY_AMQP_CHECK_SKIPPED" "an empty log_file must set REDEPLOY_AMQP_CHECK_SKIPPED=1"
+  assert_equals 0 "$REDEPLOY_ERROR_COUNT" "a skipped check must still leave REDEPLOY_ERROR_COUNT at its initialized 0 (the flag, not the count, carries the distinction)"
+  grep -qF 'could not be captured' "$TMP/classify-skipped-output" \
+    || fail "classify_amqp_connection_errors did not say the post-restart log region could not be captured"
 }
 
 test_recovery_patterns_match_source() {
@@ -1203,6 +1340,27 @@ LOG
     || fail "report_shutdown_drain did not report that there was nothing to check"
 }
 
+# fleetd #552 — a fifth outcome: log_file="" (capture_fresh_log_region's own sentinel) with a
+# previous daemon that WAS stopped this run. Distinct from "unknown" (a log was read and neither
+# signal was found in it) — here there was no log to read at all.
+test_report_shutdown_drain_skipped_when_log_missing() {
+  report_shutdown_drain "" 1 > "$TMP/drain-skipped-output" 2>&1
+  assert_equals "skipped" "$REDEPLOY_DRAIN_STATE" "an empty log_file with a previous daemon must set REDEPLOY_DRAIN_STATE=skipped"
+  grep -qF 'could not be captured' "$TMP/drain-skipped-output" \
+    || fail "report_shutdown_drain did not say the post-restart log region could not be captured"
+  if grep -qF '   ok' "$TMP/drain-skipped-output"; then
+    fail "the skipped outcome must not be printed via ok() — it is neither a pass nor a failure"
+  fi
+}
+
+# fleetd #552 — proves the had_previous_daemon=0 check really does run BEFORE the missing-log check:
+# with BOTH conditions true at once, n/a must win, because a cold start has nothing to check
+# regardless of whether the log region could be captured.
+test_report_shutdown_drain_na_wins_over_missing_log() {
+  report_shutdown_drain "" 0 > "$TMP/drain-na-and-missing-output" 2>&1
+  assert_equals "n/a" "$REDEPLOY_DRAIN_STATE" "no-previous-daemon must win over a missing log region"
+}
+
 # fleetd #512 — closes the gap none of the seven tests above can: they call report_shutdown_drain
 # directly, and sourcing stops before the main flow ever runs (the SOURCED guard), so none of them
 # can prove the main flow still calls it at all. Same shape as test_refuse_drain_gate_call_site_present
@@ -1249,6 +1407,12 @@ test_detect_supervisor_systemd_probe_error_is_unclear
 test_detect_supervisor_systemd_probe_setup_failure_is_unclear
 test_mktemp_dash_t_templates_have_x_placeholders
 test_no_unguarded_macos_only_hasher_calls
+test_no_unguarded_mktemp_assignments_after_restart
+test_capture_fresh_log_region_control
+test_capture_fresh_log_region_mktemp_failure_returns_nonzero_and_prints_nothing
+test_fresh_log_capture_failure_does_not_abort_under_sete
+test_capture_fresh_log_region_call_site_is_guarded
+test_result_section_checks_amqp_skip_before_no_error_lines
 test_require_drivable_supervisor_refuses_ambiguous
 test_require_drivable_supervisor_refuses_unclear
 test_require_drivable_supervisor_accepts_known_kinds
@@ -1289,6 +1453,7 @@ test_stop_systemd_if_loaded_dies_on_real_failure
 test_stop_systemd_if_loaded_tolerates_clean_negative
 test_stop_branches_call_tolerant_helpers_not_bare_or_true
 test_no_errors
+test_classify_amqp_connection_errors_reports_skipped_when_log_missing
 test_recovery_patterns_match_source
 test_attributed_recovered_connection_error
 test_source_derived_error_shapes_recover_by_connection
@@ -1307,6 +1472,8 @@ test_report_shutdown_drain_died_without_error_token
 test_report_shutdown_drain_complete_control
 test_report_shutdown_drain_unknown_cannot_tell
 test_report_shutdown_drain_no_previous_daemon_is_na
+test_report_shutdown_drain_skipped_when_log_missing
+test_report_shutdown_drain_na_wins_over_missing_log
 test_report_shutdown_drain_call_site_present
 test_report_shutdown_drain_ordered_after_classify_and_before_result
 test_no_error_lines_message_gated_by_drain_state