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/mcp/FleetMcp.java

@@ -527,14 +527,28 @@ public final class FleetMcp {
     }
 
     /**
-     * Pre-CB-501 identity: worker if the connection maps to a pane, otherwise the primary. Used
-     * only by the legacy constructor, where authorization is not enforced anyway.
+     * Pre-CB-501 identity: worker if the connection maps to a pane, otherwise anonymous. Used
+     * only by the legacy constructor ({@code callers == null}), where authorization is not
+     * enforced anyway — but the resolved {@link Principal} still reaches non-authz logic (e.g.
+     * {@code markSpawnedMemberPresent}, {@code recordPrimarySingleton}), so it must not be trusted
+     * with a role it did not earn.
+     *
+     * <p>fleetd #509: this used to fall back to {@link Principal#primary}, unconditionally, for
+     * every caller the connection did not resolve to a worker pane — with none of
+     * {@code CallerResolver.java:254}'s two guards ({@code isLoopback}, {@code scanComplete}).
+     * That is the exact shape #317 and #505 each closed on the enforced path; this branch was the
+     * same trap, left open on the legacy one. It now returns {@link Principal#anonymous} instead,
+     * so an unresolved legacy caller earns no authority rather than the primary's.
+     *
+     * <p>Package-private (was {@code private}) so this is unit-testable directly, the same reason
+     * {@link #denyFor} was split out — it runs inside a contextExtractor closure that only fires on
+     * a real MCP request, so nothing else could pin this behaviour.
      */
-    private static Principal legacyPrincipal(ConnectionIdentity identity, String addr, int port) {
+    static Principal legacyPrincipal(ConnectionIdentity identity, String addr, int port) {
         ConnectionIdentity.Caller c = identity.resolve(addr, port);
         return c.terminal() != null
                 ? Principal.worker(c.terminal(), c.pid())
-                : Principal.primary(c.pid());
+                : Principal.anonymous();
     }
 
     /** The caller reconstructed from the transport context. */

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/herdr/PaneLocatorTest.java

@@ -180,6 +180,32 @@ class PaneLocatorTest {
         assertTrue(outcome.complete(), "a positive match elsewhere in the scan is definitive");
     }
 
+    // --- fleetd #509: the completeness fold across clients must not collapse to "last wins" ----
+
+    @Test
+    void anEarlierClientsErrorSurvivesALaterClientsCleanNegative() {
+        // terminalForPid folds each client's Lookup.complete() with
+        //     complete = complete && outcome.complete();
+        // (PaneLocator.java:117). With a SINGLE client, a fold that keeps only the last outcome
+        // (dropping the "complete &&" prefix) agrees with the real fold — which is why 14 of the
+        // 15 pre-existing tests never catch that mutation: none of them vary the number of clients.
+        // Here the LEAD client errors on exactly the pane that would have owned the pid (so its
+        // scan is incomplete AND finds no match), and the MEMBER client cleanly reports no panes
+        // at all (a complete, negative scan). The real fold ANDs the two into false. A fold that
+        // just keeps the last client's outcome would read this as a clean true — the earlier
+        // error is erased, and CallerResolver.java:254 would read scanComplete() as true and
+        // promote an unverified caller to the primary.
+        HerdrClient lead = new FakeHerdr().processInfoFailsForPane("w2:p7", "transient");
+        HerdrClient member = new FakeHerdr().withNoPanes();
+        PaneLocator two = new PaneLocator(lead, member);
+
+        PaneLocator.Lookup outcome = two.terminalForPid(FakeHerdr.WORKER_PID);
+
+        assertNull(outcome.terminal(), "the pane that could have owned the pid was never checked");
+        assertFalse(outcome.complete(),
+                "an earlier client's error must survive a later client's clean negative");
+    }
+
     /** Minimal single-pane {@link HerdrClient} fake, purpose-built for the ancestry tests above. */
     private static final class OnePaneHerdr implements HerdrClient {
         private final ObjectMapper mapper = new ObjectMapper();

fleetd/src/test/java/dev/ltms/fleet/mcp/FleetMcpAuthzTest.java

@@ -190,6 +190,27 @@ class FleetMcpAuthzTest {
                 "no CallerResolver supplied ⇒ authorization not enforced (legacy behaviour)");
     }
 
+    /**
+     * fleetd #509: {@code legacyPrincipal} (used only when {@code callers == null}, i.e. the
+     * legacy constructor above) used to fall back to {@link Principal#primary} for ANY caller the
+     * connection did not resolve to a worker pane — no {@code isLoopback} check, no
+     * {@code scanComplete} check, unlike the enforced path's {@code CallerResolver.java:254}. A
+     * non-loopback caller (an off-host client) is exactly the case that must never earn the
+     * primary's authority, and authorization being disabled in legacy mode does not make that
+     * safe: the resolved {@link Principal} still reaches non-authz logic such as
+     * {@code markSpawnedMemberPresent} and {@code recordPrimarySingleton}.
+     */
+    @Test
+    void legacyPrincipalIsAnonymousNotPrimaryForAnUnresolvedCaller() {
+        ConnectionIdentity identity = new ConnectionIdentity(new PaneLocator(herdr), _ -> 999_999);
+        // A non-loopback address never even reaches the pane scan — resolve() short-circuits it
+        // to Caller(null, -1, true), the same "no terminal" shape a genuine primary's connection
+        // produces. legacyPrincipal must not conflate the two.
+        Principal p = FleetMcp.legacyPrincipal(identity, "8.8.8.8", 1234);
+        assertEquals(Principal.anonymous(), p,
+                "an unresolved legacy caller must earn no authority, not the primary's");
+    }
+
     // --- fleetd #439: who may see fleet_list's coordinator row ----------------------------------
 
     /**

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