scripts/redeploy-fleetd.sh

@@ -50,6 +50,14 @@
 #      absence is the real signal, because a drain that dies on its first session prints nothing
 #      else either. Warns loudly; never fails the redeploy, because by the time this is detectable
 #      the new daemon is already up and healthy.
+#  10. fleetd #603 — the same shape as trap 3 above, through a different door: the step that waited
+#      for the NEW process to appear gave it its own short, fixed 10s budget, then hard-`die`d,
+#      while the health check right after it waits a full $HEALTH_WAIT (60s) for the same daemon to
+#      answer. Under launchd, `launchctl load` returns as soon as launchd accepts the job, before the
+#      java process exists, and on a slow host that took longer than 10s — so the script died with
+#      "no process appeared" on a deploy that had fully succeeded. The pid poll now shares
+#      $HEALTH_WAIT instead of a separate, shorter budget, and a miss there falls through to the
+#      health check (the truer signal: is it actually answering?) instead of killing the run.
 #
 # Usage:
 #   scripts/redeploy-fleetd.sh              # build, confirm, restart, verify
@@ -79,7 +87,9 @@ OUT="$MODULE/fleetd.out"
 PATTERN='target/fleetd.jar'
 HEALTH='http://127.0.0.1:8765/healthz'
 STOP_WAIT=30      # seconds to wait for a clean exit before reporting failure
-HEALTH_WAIT=60    # seconds to wait for /healthz to answer after start
+HEALTH_WAIT=60    # seconds to wait for /healthz to answer after start — fleetd #603: also the pid-
+                  # poll budget below (wait_for_new_pid/await_daemon_started), so the two checks
+                  # share one named budget instead of the pid poll holding its own shorter one
 
 # CB-594: the launchd agent this script must not fight with (see trap 6 above).
 LAUNCHD_LABEL='dev.ltms.fleetd'
@@ -1067,6 +1077,67 @@ $(tail -30 "$out_file" 2>/dev/null)"
   fi
 }
 
+# fleetd #603 — the dual of wait_for_daemon_exit above: waits for a pid to APPEAR instead of
+# disappear. Used to be a bare `for _ in $(seq 10)` sitting directly in the main flow, with its own
+# short, fixed budget that had nothing to do with $HEALTH_WAIT (60s) — the budget the health check
+# right after it gets for the very same daemon. Under launchd, `launchctl load` returns as soon as
+# launchd accepts the job, before the java process exists, and on a slow host that took longer than
+# 10s — so the script died with "no process appeared" on a deploy that had fully succeeded (the
+# operator confirmed pid, healthz, and a fresh log line all present, by hand, right afterwards).
+# Sharing $HEALTH_WAIT here removes the extra, shorter magic number without inventing a new one.
+wait_for_new_pid() {
+  local timeout="$1" _i
+  for _i in $(seq "$timeout"); do
+    [ -n "$(running_pid)" ] && return 0
+    sleep 1
+  done
+  [ -n "$(running_pid)" ]
+}
+
+# fleetd #603 — the pid-appeared check and the healthz check, folded into one decision. Same shape
+# as swap_if_built/refuse_drain_gate/report_shutdown_drain above (#521/#528/#512): the main flow
+# calls this ONE function unconditionally, so there is no bare guard left for a future edit to
+# invert independently of it. That matters more here than for most of those: a plain grep of this
+# script's source cannot tell "a pid miss falls through to the health check" from "a pid miss still
+# dies" apart, because both read as the same two lines of text with only the runtime branch
+# changed — a source-text test could pass on either behavior. A real behavioural test on this
+# function is the only thing that can actually tell them apart, which is why one exists below.
+#
+# wait_for_new_pid's miss is no longer fatal by itself: it falls through to the health check, which
+# is direct proof the new daemon is up (/healthz answers 200) rather than a proxy for it (a process
+# merely existing under a name running_pid() recognises). A genuine failure still dies here: it
+# misses the pid poll AND the health poll, and report_health's own die() still prints the tail of
+# $out_file, exactly as before this fix.
+#
+# Sets NEW_PID (global — the caller's "pid N, jar ..." result line reads it afterwards) and
+# HEALTH_BODY/HEALTH_CODE (globals, the same reason report_health already needs them handed back).
+# Only ever called as a bare statement in the main flow below, never from inside a `$( )`: a die()
+# reached from inside a command substitution only kills that subshell, not the whole script, which
+# would silently turn a genuine failure back into a false "succeeded" exit (see poll_health_body's
+# own `|| true` idiom for the same hazard from the other direction).
+await_daemon_started() {
+  local health_wait="$1" old_pid="$2" health_url="$3" out_file="$4"
+  NEW_PID=""
+  if wait_for_new_pid "$health_wait"; then
+    NEW_PID="$(running_pid)"
+    [ "$NEW_PID" != "${old_pid:-}" ] || die "pid unchanged ($NEW_PID) — the old daemon never died"
+    ok "started, pid $NEW_PID"
+  else
+    warn "no process matched $PATTERN within ${health_wait}s of starting — falling through to the health check, which is the more truthful signal"
+  fi
+
+  HEALTH_BODY="$(poll_health_body "$health_url" "$health_wait")" || true
+  HEALTH_CODE="000"
+  [ -n "$HEALTH_BODY" ] || HEALTH_CODE="$(curl -s -o /dev/null -w '%{http_code}' --max-time 2 "$health_url" 2>/dev/null || echo 000)"
+  report_health "$HEALTH_BODY" "$HEALTH_CODE" "$out_file" "$health_wait"
+
+  # By now /healthz has answered (report_health above would have died otherwise), so the daemon is
+  # confirmed up even if the pid poll never matched it — see running_pid()'s own comment on
+  # under-counting if the launch method ever stops being a plain `java -jar`. Fill NEW_PID in for the
+  # result line rather than leave it blank on an otherwise fully successful redeploy.
+  [ -n "$NEW_PID" ] || NEW_PID="$(running_pid)"
+}
+
 # Ticket item 8 — `HAD_OLD_PID=0; [ -n "$OLD_PID" ] && HAD_OLD_PID=1`. Measured safe under `set -e`
 # at both bash 3.2.57 and 5.x (see the header comment trap 9 discussion in the ticket) — not a `set
 # -e` hazard, but still an untested computation feeding report_shutdown_drain's own four-way
@@ -1285,28 +1356,14 @@ say "start"
 # there now, so this line is the only thing left in the main flow to get wrong.
 dispatch_start "$SUPERVISOR_KIND"
 
-for _ in $(seq 10); do
-  NEW_PID="$(running_pid)"
-  [ -n "$NEW_PID" ] && break
-  sleep 1
-done
-[ -n "${NEW_PID:-}" ] || die "no process appeared. Last lines of $OUT:
-$(tail -20 "$OUT" 2>/dev/null)"
-[ "$NEW_PID" != "${OLD_PID:-}" ] || die "pid unchanged ($NEW_PID) — the old daemon never died"
-ok "started, pid $NEW_PID"
-
 # ------------------------------------------------------------------ verify
 
 say "verify"
 
-# fleetd #555: poll_health_body/health_is_up/report_health above. HEALTH_CODE is only ever
-# consulted by report_health when the body came back empty; `|| true` on both assignments is the
-# same "an absent/failing command substitution must not kill the script under set -e" idiom the
-# swap/drain helpers already rely on (see poll_health_body's own comment).
-HEALTH_BODY="$(poll_health_body "$HEALTH" "$HEALTH_WAIT")" || true
-HEALTH_CODE="000"
-[ -n "$HEALTH_BODY" ] || HEALTH_CODE="$(curl -s -o /dev/null -w '%{http_code}' --max-time 2 "$HEALTH" 2>/dev/null || echo 000)"
-report_health "$HEALTH_BODY" "$HEALTH_CODE" "$OUT" "$HEALTH_WAIT"
+# fleetd #603: await_daemon_started above folds the pid-appeared check and the healthz check into
+# one decision — see its own comment for why a bare `if` here, split back into the old two pieces,
+# would put back an untestable branch this ticket exists to close.
+await_daemon_started "$HEALTH_WAIT" "$OLD_PID" "$HEALTH" "$OUT"
 
 # A fresh listening line, strictly after the restart mark. An old daemon that never died would
 # otherwise let an old line pass for a new one.
@@ -1361,7 +1418,7 @@ report_shutdown_drain "$FRESH_LOG" "$HAD_OLD_PID"
 assert_single_daemon "$(running_pid)"
 
 say "result"
-ok "pid $NEW_PID, jar $(jar_id)"
+ok "pid ${NEW_PID:-unknown}, jar $(jar_id)"
 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

scripts/test-redeploy-fleetd.sh

@@ -770,6 +770,137 @@ test_wait_for_daemon_exit_times_out_if_pid_never_clears() {
   source "$ROOT/scripts/redeploy-fleetd.sh"   # restore the real running_pid/sleep for later tests
 }
 
+# fleetd #603 — wait_for_new_pid is the dual of wait_for_daemon_exit above: it must not report
+# success while running_pid() still answers empty, and must report success the moment a pid
+# appears. Same counter-file idiom as test_wait_for_daemon_exit_returns_true_once_pid_clears above,
+# for the same reason (running_pid() runs inside a `$(...)` subshell on every call).
+test_wait_for_new_pid_returns_true_once_pid_appears() {
+  local counter_file="$TMP/wait-new-pid-calls" final_calls
+  printf '0' > "$counter_file"
+  running_pid() {
+    local n
+    n="$(cat "$counter_file")"
+    n=$((n + 1))
+    printf '%s' "$n" > "$counter_file"
+    if [ "$n" -lt 3 ]; then printf ''; else printf '4242'; fi
+  }
+  sleep() { :; }
+  wait_for_new_pid 10 || fail "wait_for_new_pid did not report success once the pid appeared"
+  final_calls="$(cat "$counter_file")"
+  [ "$final_calls" -ge 3 ] || fail "wait_for_new_pid returned before actually re-checking running_pid"
+  source "$ROOT/scripts/redeploy-fleetd.sh"   # restore the real running_pid/sleep for later tests
+}
+
+test_wait_for_new_pid_times_out_if_pid_never_appears() {
+  local rc=0
+  running_pid() { printf ''; }
+  sleep() { :; }
+  wait_for_new_pid 3 || rc=$?
+  [ "$rc" -ne 0 ] || fail "wait_for_new_pid reported success while the pid never appeared"
+  source "$ROOT/scripts/redeploy-fleetd.sh"   # restore the real running_pid/sleep for later tests
+}
+
+# fleetd #603 — await_daemon_started folds the pid-appeared check and the healthz check into one
+# decision (see its own comment in redeploy-fleetd.sh for why a source-text grep cannot tell the two
+# possible behaviors apart here). These two tests are the ticket's own acceptance criteria, run
+# together in this one suite invocation so neither can be satisfied by code that never fails at all:
+#
+#   1. a slow start must still succeed — running_pid mimics a process that does not appear until
+#      well after the OLD, buggy 10-second budget, but does appear, and healthz answers.
+#   2. a genuine failure must still fail, and still print the log tail — running_pid and the health
+#      check both report nothing at all, ever.
+test_await_daemon_started_slow_pid_then_healthy_succeeds() {
+  source "$ROOT/scripts/redeploy-fleetd.sh"
+  stub_die_recorder
+  local counter_file="$TMP/await-slow-pid-calls" output
+  printf '0' > "$counter_file"
+  running_pid() {
+    local n
+    n="$(cat "$counter_file")"
+    n=$((n + 1))
+    printf '%s' "$n" > "$counter_file"
+    # Stays empty well past the old 10-second budget, then appears — the exact shape #603 reports.
+    if [ "$n" -lt 12 ]; then printf ''; else printf '4242'; fi
+  }
+  sleep() { :; }
+  poll_health_body() { printf '{"status":"ok"}'; return 0; }
+  # NOT `output="$(await_daemon_started ...)"`: that would run the call in a subshell, and
+  # NEW_PID — a plain global assignment inside the function, by design (see its own comment) — would
+  # die with that subshell instead of reaching this test's own shell. Redirect to a file instead, the
+  # same hazard await_daemon_started's own comment warns die() itself is subject to.
+  await_daemon_started 60 "" "http://ignored/healthz" "$TMP/await-slow-pid.out" \
+    > "$TMP/await-slow-pid-output.log" 2>&1
+  output="$(cat "$TMP/await-slow-pid-output.log")"
+  [ "$DIED_CALLED" = 0 ] \
+    || fail "await_daemon_started must not die on a slow-but-real start: $DIED_MESSAGE"
+  assert_equals "4242" "$NEW_PID" "await_daemon_started NEW_PID after a slow-but-real start"
+  printf '%s' "$output" | grep -qF 'started, pid 4242' \
+    || fail "await_daemon_started did not report the pid once it finally appeared"
+  source "$ROOT/scripts/redeploy-fleetd.sh"
+}
+
+test_await_daemon_started_never_appears_dies_with_log_tail() {
+  source "$ROOT/scripts/redeploy-fleetd.sh"
+  stub_die_recorder
+  local out_file="$TMP/await-never-appears.out"
+  printf 'boot line one\nboot line two\n' > "$out_file"
+  running_pid() { printf ''; }
+  sleep() { :; }
+  poll_health_body() { return 1; }
+  await_daemon_started 2 "" "http://127.0.0.1:1/healthz" "$out_file" > /dev/null 2>&1
+  [ "$DIED_CALLED" = 1 ] \
+    || fail "await_daemon_started must die when the daemon never appears and never becomes healthy"
+  printf '%s' "$DIED_MESSAGE" | grep -qF 'never answered' \
+    || fail "await_daemon_started die message does not say healthz never answered"
+  printf '%s' "$DIED_MESSAGE" | grep -qF 'boot line two' \
+    || fail "await_daemon_started die message does not include the log tail"
+  source "$ROOT/scripts/redeploy-fleetd.sh"
+}
+
+# fleetd #603 review — the path the fall-through actually exists for, and the one gap a lead
+# mutation found in the first version of this test file: running_pid() NEVER finds anything (as its
+# own doc comment says it eventually will, once the daemon stops being launched as a plain
+# `java -jar` its allowlist recognises), while /healthz answers anyway. Neither of the two tests
+# above drives this: the slow-pid test has the pid appear, so the `else` branch never runs, and the
+# never-appears test fails BOTH checks, so it dies either way and cannot tell which branch fired.
+# This must not die, must warn (so the operator is told the pid could not be identified), and must
+# leave NEW_PID empty — the honest "could not establish this" answer, never a guessed pid, which is
+# what the final result line's `${NEW_PID:-unknown}` fallback exists to print truthfully.
+#
+# Proof this actually pins the behavior, not just the source text (paste from a real run, not
+# claimed): reverting the `warn` below back to `die "no process appeared"` (the old fleetd #603
+# defect, reintroduced) turns this one test red —
+#   FAIL: await_daemon_started must not die when the pid is never found but healthz answers
+# — and restoring `warn` turns the whole suite green again. Both halves observed, not asserted.
+test_await_daemon_started_pid_never_found_but_healthy_warns_and_survives() {
+  source "$ROOT/scripts/redeploy-fleetd.sh"
+  stub_die_recorder
+  local out_file="$TMP/await-pid-never-found.out" output
+  printf 'boot line\n' > "$out_file"
+  running_pid() { printf ''; }
+  sleep() { :; }
+  poll_health_body() { printf '{"status":"ok"}'; return 0; }
+  # NOT `output="$(await_daemon_started ...)"` — see the slow-pid test above for why that would
+  # drop NEW_PID's assignment in a subshell instead of reaching this test's own shell.
+  await_daemon_started 3 "" "http://ignored/healthz" "$out_file" \
+    > "$TMP/await-pid-never-found-output.log" 2>&1
+  output="$(cat "$TMP/await-pid-never-found-output.log")"
+  [ "$DIED_CALLED" = 0 ] \
+    || fail "await_daemon_started must not die when the pid is never found but healthz answers: $DIED_MESSAGE"
+  printf '%s' "$output" | grep -qF 'falling through to the health check' \
+    || fail "await_daemon_started did not warn that the pid could not be identified"
+  assert_equals "" "$NEW_PID" \
+    "await_daemon_started NEW_PID when the pid is never found but healthz answers — must stay empty, never a guessed pid"
+  source "$ROOT/scripts/redeploy-fleetd.sh"
+}
+
+test_await_daemon_started_call_site_present() {
+  local src="$ROOT/scripts/redeploy-fleetd.sh" call_line
+  call_line="$(grep -Fn 'await_daemon_started "$HEALTH_WAIT" "$OLD_PID" "$HEALTH" "$OUT"' "$src" | head -1 | cut -d: -f1 || true)"
+  [ -n "$call_line" ] \
+    || fail "could not find the main flow's await_daemon_started call site in redeploy-fleetd.sh"
+}
+
 # fleetd #521 — the swap step's guard, at two levels.
 #
 # The first two tests call the predicate should_swap() directly. They pin its logic, and that is all
@@ -1350,9 +1481,11 @@ test_poll_health_body_returns_nonzero_when_unreachable() {
 
 test_report_health_call_site_present() {
   local src="$ROOT/scripts/redeploy-fleetd.sh" call_line
-  call_line="$(grep -Fn 'report_health "$HEALTH_BODY" "$HEALTH_CODE" "$OUT" "$HEALTH_WAIT"' "$src" | head -1 | cut -d: -f1 || true)"
+  # fleetd #603 — moved from a literal main-flow call into await_daemon_started (see its own
+  # comment above for why); this now finds the call inside that function instead.
+  call_line="$(grep -Fn 'report_health "$HEALTH_BODY" "$HEALTH_CODE" "$out_file" "$health_wait"' "$src" | head -1 | cut -d: -f1 || true)"
   [ -n "$call_line" ] \
-    || fail "could not find the main flow's report_health call site in redeploy-fleetd.sh"
+    || fail "could not find await_daemon_started's report_health call site in redeploy-fleetd.sh"
 }
 
 # fleetd #555 item 8 — `HAD_OLD_PID=0; [ -n "$OLD_PID" ] && HAD_OLD_PID=1`. Measured safe under
@@ -2041,6 +2174,12 @@ test_require_no_build_jar_dies_when_absent
 test_require_no_build_jar_accepts_present_jar
 test_wait_for_daemon_exit_returns_true_once_pid_clears
 test_wait_for_daemon_exit_times_out_if_pid_never_clears
+test_wait_for_new_pid_returns_true_once_pid_appears
+test_wait_for_new_pid_times_out_if_pid_never_appears
+test_await_daemon_started_slow_pid_then_healthy_succeeds
+test_await_daemon_started_never_appears_dies_with_log_tail
+test_await_daemon_started_pid_never_found_but_healthy_warns_and_survives
+test_await_daemon_started_call_site_present
 test_swap_ordered_after_wait_and_before_start
 test_drain_gate_abort_message_says_no_no_build
 test_drain_gate_refusal_build_ran_staged_present