fleetd #512 (part 1): log a positive completion line when drainAll finishes

drainAll used to log nothing on a clean drain — both existing log calls
(drainSnapshot's per-session failure, drainAll's straggler-sweep warning)
sit on abnormal paths, so "drained fine" and "died on the first session"
looked identical: no log line either way.

Add one log.info at the end of drainAll: "drain complete: released=N
abandoned=M (still BUSY at the shutdown deadline)". It fires on the
normal path, including the all-zero case, and folds both drainSnapshot
passes (main snapshot + straggler sweep) into one line.

drainSnapshot now returns a private DrainTally(released, abandoned)
record instead of void, and the private release(paneId, cause) overload
now returns the removed MemberSession (previously void) so drainSnapshot
can read its state at the moment of removal — the same check
logPreservedForShutdown already makes. Both signature changes are
private with a single call site, so the blast radius stays small.

fleetd/src/main/java/dev/ltms/fleet/session/SessionManager.java

@@ -302,9 +302,10 @@ public final class SessionManager implements TurnListener {
      * with no copy and no error. Do NOT fuse these back together; the cost of an orphaned worktree
      * is a logged path an operator can reclaim, the cost of a deleted one is unrecoverable work.
      */
-    private void release(String paneId, ReleaseCause cause) {
+    private MemberSession release(String paneId, ReleaseCause cause) {
         MemberSession removed = registry.remove(paneId);
         releaseRemoved(paneId, removed, handles.remove(paneId), cause);
+        return removed;
     }
 
     /**
@@ -1064,16 +1065,39 @@ public final class SessionManager implements TurnListener {
      * drain (see above), and a straggler must not buy the drain more time than the flag it lost the
      * race against would have. In the ordinary case the sweep finds nothing and costs one empty
      * {@link #roster()} call.
+     *
+     * <p>fleetd #512: a drain that releases every session cleanly used to log nothing at all — the
+     * only log calls in this method and {@link #drainSnapshot} sit on abnormal paths, so "nothing
+     * logged" was indistinguishable from "died on the first session". The {@code log.info} at the
+     * end below is a positive assertion that the drain actually finished, on the normal path,
+     * every time — including the all-zero case, which is a common and legitimate outcome (no
+     * members were live) and must still produce the line. Both {@link #drainSnapshot} passes (the
+     * main snapshot and the straggler sweep) are folded into the one line: a caller reading two
+     * lines could not tell a two-pass drain from two separate drains.
      */
     void drainAll(long timeoutNanos) {
         long deadline = System.nanoTime() + timeoutNanos;
         draining.set(true);
-        drainSnapshot(roster(), deadline);
+        DrainTally tally = drainSnapshot(roster(), deadline);
         List<MemberSession> stragglers = roster();
         if (!stragglers.isEmpty()) {
             log.warn("drain sweep found {} session(s) registered after the drain snapshot was "
                     + "taken (raced past the shutdown guard); draining them too", stragglers.size());
-            drainSnapshot(stragglers, deadline);
+            tally = tally.plus(drainSnapshot(stragglers, deadline));
+        }
+        log.info("drain complete: released={} abandoned={} (still BUSY at the shutdown deadline)",
+                tally.released(), tally.abandoned());
+    }
+
+    /**
+     * Running count for one {@link #drainAll} invocation, folded across both {@link #drainSnapshot}
+     * passes (fleetd #512). {@code abandoned} counts sessions that were still {@code BUSY} at the
+     * moment they were released — i.e. the whole-drain deadline passed before they left {@code BUSY}
+     * on their own (see {@link #drainSnapshot}) — a subset of {@code released}, not additional to it.
+     */
+    private record DrainTally(int released, int abandoned) {
+        private DrainTally plus(DrainTally other) {
+            return new DrainTally(released + other.released, abandoned + other.abandoned);
         }
     }
 
@@ -1081,8 +1105,12 @@ public final class SessionManager implements TurnListener {
      * Drain exactly the sessions in {@code snapshot}, waiting out a {@code BUSY} one against the
      * shared whole-drain {@code deadline} before releasing it. Shared by {@link #drainAll}'s main
      * pass and its post-loop straggler sweep (fleetd #308) so both honor the same one budget.
+     * Returns how many sessions this pass released, and how many of those were still {@code BUSY}
+     * (abandoned mid-turn) at the moment of release.
      */
-    private void drainSnapshot(List<MemberSession> snapshot, long deadline) {
+    private DrainTally drainSnapshot(List<MemberSession> snapshot, long deadline) {
+        int released = 0;
+        int abandoned = 0;
         for (MemberSession s : snapshot) {
             try {
                 if (s.state() == MemberSession.State.BUSY) {
@@ -1100,11 +1128,16 @@ public final class SessionManager implements TurnListener {
                         }
                     }
                 }
-                release(s.paneId(), ReleaseCause.SHUTDOWN);
+                MemberSession removed = release(s.paneId(), ReleaseCause.SHUTDOWN);
+                released++;
+                if (removed != null && removed.state() == MemberSession.State.BUSY) {
+                    abandoned++;
+                }
             } catch (RuntimeException e) {
                 log.warn("drain failed for pane={}; continuing with remaining sessions", s.paneId(), e);
             }
         }
+        return new DrainTally(released, abandoned);
     }
 
     /**

fleetd/src/test/java/dev/ltms/fleet/session/SessionManagerTest.java

@@ -902,6 +902,104 @@ class SessionManagerTest {
                 .count();
     }
 
+    /**
+     * fleetd #512: a drain that releases every session cleanly used to log nothing at all — the
+     * two log calls in {@code drainAll}/{@code drainSnapshot} both sit on abnormal paths, so
+     * "clean drain" and "died on the first session" were indistinguishable. This asserts the new
+     * {@code log.info} line fires on the ordinary, nothing-went-wrong path, and that its numbers
+     * are the real counts (two released, zero abandoned) rather than just a non-empty string.
+     */
+    @Test
+    void drainAllLogsACompletionLineWithTheRealCountsOnACleanDrain() {
+        FakeHerdr herdr = new FakeHerdr();
+        SessionManager sessions = sessionManager(herdr);
+        MemberSession first = sessions.acquire("ltms-local", "/one", "/caller", "ownerOne");
+        MemberSession second = sessions.acquire("ltms-local", "/two", "/caller", "ownerTwo");
+        sessions.asPresence().markPresent(first.terminalId());
+        sessions.asPresence().markPresent(second.terminalId());
+        // Both stay READY — neither is delivered a turn, so neither is BUSY and the drain below
+        // has nothing abnormal to hit.
+
+        LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
+        ch.qos.logback.classic.Logger sessionLog =
+                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
+        ListAppender<ILoggingEvent> appender = new ListAppender<>();
+        appender.setContext(ctx);
+        appender.start();
+        sessionLog.addAppender(appender);
+        // Pin INFO explicitly: another test in this class (run order is not guaranteed) leaves the
+        // shared SessionManager logger pinned at WARN via setLevel and never restores it, which
+        // would silently swallow the log.info assertion below.
+        sessionLog.setLevel(Level.INFO);
+        try {
+            sessions.drainAll(TimeUnit.MILLISECONDS.toNanos(100));
+
+            assertTrue(sessions.roster().isEmpty(), "precondition: the drain actually ran");
+            String info = appender.list.stream()
+                    .filter(e -> e.getLevel().equals(Level.INFO))
+                    .map(ILoggingEvent::getFormattedMessage)
+                    .filter(m -> m.contains("drain complete"))
+                    .findFirst()
+                    .orElse("no drain-complete INFO logged");
+            assertTrue(info.contains("released=2"),
+                    "both released sessions must be counted: " + info);
+            assertTrue(info.contains("abandoned=0"),
+                    "neither session was BUSY, so nothing was abandoned mid-turn: " + info);
+        } finally {
+            sessionLog.detachAppender(appender);
+            sessionLog.setLevel(null);
+        }
+    }
+
+    /**
+     * fleetd #512: the same completion line must also report a non-zero abandoned count when a
+     * session is still {@code BUSY} once the whole-drain deadline passes — the case the ticket
+     * calls out as the one a script needs to be able to see. Reuses the same BUSY/READY mix as
+     * {@link #drainAllReleasesBusyAndReadySessionsAndWaitsForBusy}, which already forces the busy
+     * session to spin until the real-time deadline expires (its state never leaves BUSY on its
+     * own), and adds the log assertion that test does not make.
+     */
+    @Test
+    void drainAllLogsANonZeroAbandonedCountForASessionStillBusyAtTheDeadline() {
+        FakeHerdr herdr = new FakeHerdr();
+        SessionManager sessions = sessionManager(herdr);
+        MemberSession ready = sessions.acquire("ltms-local", "/ready", "/caller", "ownerR");
+        MemberSession busy = sessions.acquire("ltms-local", "/busy", "/caller", "ownerB");
+        sessions.asPresence().markPresent(ready.terminalId());
+        sessions.asPresence().markPresent(busy.terminalId());
+        sessions.onDelivered(busy.terminalId(), TestTurnTokens.inert(busy.terminalId()));
+        // busy never leaves BUSY — no completion is delivered — so the drain below must spin the
+        // full timeout and then release it anyway, counting it abandoned.
+
+        LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
+        ch.qos.logback.classic.Logger sessionLog =
+                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
+        ListAppender<ILoggingEvent> appender = new ListAppender<>();
+        appender.setContext(ctx);
+        appender.start();
+        sessionLog.addAppender(appender);
+        // Pin INFO explicitly — see the comment in drainAllLogsACompletionLineWithTheRealCountsOnACleanDrain.
+        sessionLog.setLevel(Level.INFO);
+        try {
+            sessions.drainAll(TimeUnit.MILLISECONDS.toNanos(100));
+
+            assertTrue(sessions.roster().isEmpty(), "precondition: the drain actually ran");
+            String info = appender.list.stream()
+                    .filter(e -> e.getLevel().equals(Level.INFO))
+                    .map(ILoggingEvent::getFormattedMessage)
+                    .filter(m -> m.contains("drain complete"))
+                    .findFirst()
+                    .orElse("no drain-complete INFO logged");
+            assertTrue(info.contains("released=2"),
+                    "both the ready and the busy session are released: " + info);
+            assertTrue(info.contains("abandoned=1"),
+                    "the busy session hit the deadline still BUSY and must be counted: " + info);
+        } finally {
+            sessionLog.detachAppender(appender);
+            sessionLog.setLevel(null);
+        }
+    }
+
     // --- fleetd #308: a spawn accepted while the shutdown drain is running must not orphan ---
 
     @Test

scripts/probe-member-credentials.sh

@@ -65,6 +65,27 @@
 # credential the member holds in full.
 #
 set -uo pipefail
+# `pipefail` is not what catches the parser failure handled below (fleetd #500): in
+# `printf '%s' "$POLICY_JSON" | jq -r '...'`, jq is the LAST element of the pipe, so the pipeline's
+# own exit status is already jq's status, with or without pipefail. It is kept as insurance for if
+# a post-processing stage is ever appended after the parser (e.g. `| tail -n +2`) — at that point
+# the parser would sit upstream and pipefail becomes the only thing that still reports its status.
+
+# --- refuse on an interpreter that cannot run this script (fleetd #500) -------------------------
+#
+# mapfile, used below to parse the policy response, was added in bash 4.0. macOS ships bash 3.2.57
+# at /bin/bash, which predates it. This script's own `set -uo pipefail` does not catch a missing
+# mapfile: the builtin just fails with "command not found" on stderr, and every line below that
+# reads the array it would have filled uses a `:-` default or a slice, neither of which `set -u`
+# catches on an unset array. Left unguarded, that chain ends in the "0 known names" refusal further
+# down — a claim about the POLICY, for a failure that is actually about the INTERPRETER. So the
+# interpreter is checked once, explicitly, before it is asked to do anything mapfile depends on.
+if (( ${BASH_VERSINFO[0]} < 4 )); then
+  echo "refusing to run: this script uses mapfile, which needs bash 4 or newer. This shell is bash" \
+       "${BASH_VERSION:-<unknown, no \$BASH_VERSION>}. Re-run it under a newer bash, for example:" \
+       "\"\$(command -v bash)\" \"$0\"" "$@" >&2
+  exit 3
+fi
 
 FLEETD_HOST="${FLEETD_HOST:-http://127.0.0.1:8765}"
 POLICY_URL="${FLEETD_HOST%/}/member-credentials"
@@ -124,16 +145,32 @@ fi
 # One parse pass: line 1 = present (true/false/null), line 2 = policy mode (possibly blank),
 # lines 3-5 = knownCount/allowedCount/blockedCount, remaining lines = the known[] names. A single
 # pass avoids re-parsing (and re-risking a truthiness bug) five separate times.
+#
+# This used to feed the parser straight into `mapfile -t _FIELDS < <(producer)`. That form cannot
+# see the producer fail: `<` `<(...)` is a process substitution, not a pipeline, so `set -o
+# pipefail` does not reach inside it, and mapfile's own exit status reports whether the BUILTIN
+# ran, not whether the command substituted into it succeeded — a failing jq or python3 there still
+# leaves mapfile at rc=0 with an empty array, read as a parse that genuinely found nothing (fleetd
+# #500). Capturing the parser's output with command substitution first, and checking ITS exit
+# status, reports the producer's real failure while the fact still exists — before it is handed to
+# mapfile at all.
+#
+# mapfile then reads from that captured string with `<<<` (a herestring), not `< <(...)`: `<<<`
+# materialises the whole string in memory first, where `< <(...)` would stream it. That only
+# matters for a large producer; this one is a short credential-name policy response, so the
+# tradeoff is irrelevant here — noted because it would not be for every producer.
 if command -v jq >/dev/null 2>&1; then
-  mapfile -t _FIELDS < <(printf '%s' "$POLICY_JSON" | jq -r '
+  _FIELDS_RAW="$(printf '%s' "$POLICY_JSON" | jq -r '
       (.present | tostring),
       (.policy // ""),
       (.knownCount // 0 | tostring),
       (.allowedCount // 0 | tostring),
       (.blockedCount // 0 | tostring),
-      (.known[]? // empty)')
+      (.known[]? // empty)')"
+  _PARSE_STATUS=$?
+  _PARSER_NAME="jq"
 else
-  mapfile -t _FIELDS < <(printf '%s' "$POLICY_JSON" | python3 - <<'PY'
+  _FIELDS_RAW="$(printf '%s' "$POLICY_JSON" | python3 - <<'PY'
 import json, sys
 data = json.load(sys.stdin)
 print(str(data.get("present")))
@@ -144,7 +181,34 @@ print(data.get("blockedCount") if data.get("blockedCount") is not None else 0)
 for n in (data.get("known") or []):
     print(n)
 PY
-  )
+  )"
+  _PARSE_STATUS=$?
+  _PARSER_NAME="python3"
+fi
+
+if [ "$_PARSE_STATUS" -ne 0 ]; then
+  echo "refusing to run: could not parse the policy fetched from $POLICY_URL — $_PARSER_NAME exited" \
+       "non-zero (status $_PARSE_STATUS). That is a parser failure, not a claim about the policy" \
+       "itself; the policy response has not been read." >&2
+  exit 4
+fi
+
+mapfile -t _FIELDS <<< "$_FIELDS_RAW"
+
+# Arity check — the CORRECTNESS fix (fleetd #500). A parser that exits 0 can still return fewer
+# than the 5 fixed fields (present, policy mode, 3 counts) that every line below this expects,
+# whatever the reason: a producer that printed nothing, malformed JSON that jq/python3 still
+# accepted, or a schema change upstream. The slice just below this (`_FIELDS[@]:5`) does not fire
+# `set -u` on an unset OR a short array, and every fixed-field read above used a `:-` default, so
+# without this check a short `_FIELDS` reaches the "0 known names" guard further down with the
+# same look as a policy that genuinely has 0 names. Check the count here, at the one point the
+# fact is still present, before the slice consumes it.
+if (( ${#_FIELDS[@]} < 5 )); then
+  echo "refusing to run: the policy parser ($_PARSER_NAME) returned ${#_FIELDS[@]} field(s); at" \
+       "least 5 are required (present, policy mode, knownCount, allowedCount, blockedCount). The" \
+       "parse ran but its shape is wrong — this is not a claim about how many names the policy" \
+       "knows." >&2
+  exit 5
 fi
 
 PRESENT="${_FIELDS[0]:-null}"
@@ -164,19 +228,21 @@ case "$KNOWN_COUNT_REPORTED" in
     ;;
 esac
 
-# --- guard the denominator explicitly — never proceed on a zero/short count ---------------------
+# --- guard the denominator explicitly — never proceed on a zero count ---------------------------
 #
-# This is the exact trap named in the ticket: an empty (or truncated) NAMES array passes every
-# subsequent "is it set" check vacuously and prints a table that LOOKS complete. So this is checked
-# before anything else runs, with a message that says why, not just that it failed.
+# This is the exact trap named in the ticket: an empty NAMES array passes every subsequent "is it
+# set" check vacuously and prints a table that LOOKS complete. By this point the interpreter gate,
+# the parser-exit-status check, and the arity check above have already ruled out "the interpreter
+# couldn't run mapfile", "the parser failed", and "the parser returned the wrong shape" — so a zero
+# count reaching here really does mean the policy itself reports 0 known names, not a swallowed
+# failure upstream. That is still checked before anything else runs, with a message that says so.
 if [ "${#NAMES[@]}" -eq 0 ] || [ "$KNOWN_COUNT_REPORTED" -eq 0 ]; then
   cat >&2 <<EOF
 refusing to run: the policy fetched from $POLICY_URL contains 0 known names (present=${PRESENT:-unknown}).
 
-Either memberCredentials: is absent/empty on the running daemon (nothing is protected — see fleetd's
-own startup warning), or the response could not be parsed. Either way, checking zero names would
-print a clean-looking table for a policy that protects nothing, or for a probe that read nothing.
-This is refused rather than reported as a pass.
+memberCredentials: is absent or empty on the running daemon — nothing is protected (see fleetd's own
+startup warning). Checking zero names would print a clean-looking table for a policy that protects
+nothing. This is refused rather than reported as a pass.
 EOF
   exit 1
 fi

scripts/redeploy-fleetd.sh

@@ -615,8 +615,9 @@ if [ -n "$OLD_PID" ] && [ "$ASSUME_YES" = 0 ]; then
     # than before this run started, even though the running daemon itself was never touched.
     if [ "$DO_BUILD" = 1 ] && [ -f "$JAR_STAGED" ]; then
       die "aborted — the running daemon was NOT touched, but the freshly built jar is sitting at
-          $JAR_STAGED, not yet swapped into $JAR. Rerun (with or without --no-build) to finish the
-          restart, or remove $JAR_STAGED by hand if you want to discard this build."
+          $JAR_STAGED, not yet swapped into $JAR. Rerun WITHOUT --no-build to finish the restart —
+          the freshly built jar is no longer at the live path that --no-build requires — or
+          remove $JAR_STAGED by hand if you want to discard this build."
     fi
     die "aborted — nothing changed"
   fi

scripts/test-redeploy-fleetd.sh

@@ -206,6 +206,28 @@ test_assert_single_daemon_rejects_two_pids() {
   printf '%s' "$output" | grep -qF '4343' || fail "refusal message does not list the pids it found"
 }
 
+# fleetd #511 — jar_id()'s no-argument default was unpinned by any test: nothing proved it reports
+# $JAR (the live path) rather than $JAR_STAGED. Both halves matter, so this pins both: the bare call
+# must hash the live jar, and an explicit path argument must hash THAT file, not fall back to $JAR.
+# Two files with different content, so a default pointed at the wrong one reports the wrong hash
+# rather than accidentally matching.
+test_jar_id_defaults_to_live_and_reports_explicit_path() {
+  local dir saved_jar="$JAR" saved_staged="$JAR_STAGED"
+  local live_hash staged_hash default_result explicit_result
+  dir="$TMP/jar-id"; mkdir -p "$dir"
+  JAR="$dir/fleetd.jar"; JAR_STAGED="$dir/fleetd-new.jar"
+  printf 'live jar bytes' > "$JAR"
+  printf 'staged jar bytes, not the same content' > "$JAR_STAGED"
+  live_hash="$(shasum -a 256 "$JAR" | cut -c1-12)"
+  staged_hash="$(shasum -a 256 "$JAR_STAGED" | cut -c1-12)"
+  default_result="$(jar_id)"
+  explicit_result="$(jar_id "$JAR_STAGED")"
+  JAR="$saved_jar"; JAR_STAGED="$saved_staged"
+  [ "$live_hash" != "$staged_hash" ] || fail "test fixture error: live and staged jars hashed the same"
+  assert_equals "$live_hash" "$default_result" "jar_id with no arguments must report the hash of \$JAR"
+  assert_equals "$staged_hash" "$explicit_result" "jar_id \"\$JAR_STAGED\" must report the hash of the staged jar, not fall back to \$JAR"
+}
+
 # fleetd #493 — never build into the path a running process holds. stage_built_jar/swap_staged_jar
 # are exercised directly against real files on disk (not stubs), because the whole point is file
 # behavior (does the content move, does the source disappear, does a failure leave both sides
@@ -344,6 +366,26 @@ test_swap_ordered_after_wait_and_before_start() {
     || fail "swap_staged_jar (line $swap_line) is not before the start section (line $start_line)"
 }
 
+# fleetd #511: the drain-gate abort message (fired when a build has staged a jar but the operator
+# declines the drain confirmation) used to tell the operator to "Rerun (with or without --no-build)"
+# to finish the restart. That is wrong — by the time this message can fire, stage_built_jar has
+# already moved the jar off $JAR, so a rerun WITH --no-build hits require_no_build_jar's own refusal
+# ("no jar at $JAR — run without --no-build"). Like test_swap_ordered_after_wait_and_before_start
+# above, this code path is never reached by sourcing (the SOURCED guard stops before the main flow),
+# so the only way to pin its exact wording is to read the source.
+test_drain_gate_abort_message_says_no_no_build() {
+  local src="$ROOT/scripts/redeploy-fleetd.sh" msg
+  msg="$(grep -A3 -F 'aborted — the running daemon was NOT touched, but the freshly built jar is sitting at' "$src")"
+  [ -n "$msg" ] || fail "could not find the drain-gate staged-jar abort message in redeploy-fleetd.sh"
+  if printf '%s' "$msg" | grep -qF 'with or without --no-build'; then
+    fail "abort message still claims a rerun WITH --no-build can finish the restart"
+  fi
+  printf '%s' "$msg" | grep -qF 'WITHOUT --no-build' \
+    || fail "abort message does not tell the operator to rerun without --no-build"
+  printf '%s' "$msg" | grep -qF 'no longer at the live path' \
+    || fail "abort message does not say why --no-build cannot finish the restart"
+}
+
 test_no_errors() {
   cat > "$TMP/no-errors.log" <<'LOG'
 2026-09-05 12:00:00 INFO fleetd listening
@@ -555,6 +597,7 @@ test_require_drivable_supervisor_accepts_known_kinds
 test_count_daemon_pids
 test_assert_single_daemon_accepts_one_pid
 test_assert_single_daemon_rejects_two_pids
+test_jar_id_defaults_to_live_and_reports_explicit_path
 test_stage_built_jar_moves_off_live_path
 test_stage_built_jar_dies_when_build_produced_nothing
 test_swap_staged_jar_moves_staged_onto_live
@@ -565,6 +608,7 @@ 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_swap_ordered_after_wait_and_before_start
+test_drain_gate_abort_message_says_no_no_build
 test_no_errors
 test_recovery_patterns_match_source
 test_attributed_recovered_connection_error