diff --git a/scripts/redeploy-fleetd.sh b/scripts/redeploy-fleetd.sh index e505979..f785b90 100755 --- a/scripts/redeploy-fleetd.sh +++ b/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 diff --git a/scripts/test-redeploy-fleetd.sh b/scripts/test-redeploy-fleetd.sh index f2267ce..864f455 100755 --- a/scripts/test-redeploy-fleetd.sh +++ b/scripts/test-redeploy-fleetd.sh @@ -770,6 +770,100 @@ 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" +} + +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 +1444,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 +2137,11 @@ 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_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