Merge #534: detect a died shutdown drain the ERROR count is blind to (fleetd #512 part 2)

Verified independently. The branch is based on 8335b12 while main is at bec87f9, so I merged locally first and tested the MERGED tree, not the branch — a clean auto-merge is not a working merge.

Merged tree checks:
- `bash -n` exit 0 on both scripts, under /bin/bash 3.2.57 and env bash 5.3.9.
- Suite exit 0, 0 lines matching `^FAIL:`, 255 bytes of output. 60 test functions defined, 60 invoked, and no defined-but-never-invoked orphan (checked with a comm against the invocation list, not by comparing two counts — two equal counts can both be wrong).
- My own comment fix from bec87f9 survived the merge and is still at :317.

I ran two mutations the worker did not, per "mutate the half the worker did not":

(A) The one that matters, because it is the defect this ticket exists to prevent: collapsed the `unknown` state into `complete`, so "cannot tell" reports as a pass. Result exit 1, one FAIL: `cannot-tell fixture must set REDEPLOY_DRAIN_STATE=unknown: expected unknown, got complete`. So the third state is genuinely load-bearing, not decoration.

(B) Broke the positive check: changed `find_drain_complete_line`'s pattern from `drain complete: released=` to `drain finished: released=`, one site. Result exit 1, one FAIL: `find_drain_complete_line did not capture the present line`.

Proof that (B) applied, against a pristine copy: the full grep line 1 -> 0, the mutant form 0 -> 1, and the bare phrase 2 -> 1 with the comment occurrence untouched. Both files restored byte-identical; `git diff --quiet` clean; green control re-run.

A note on my own proof cell for (B), because it was wrong the first time. I wrote the counts with escaped double quotes inside an already double-quoted command substitution, so the shell split the pattern on spaces and grep treated the words as filenames. It printed "2 and 2" alongside `ugrep: No such file or directory` warnings — a symmetric, plausible-looking pair that meant nothing. The kill itself was never in doubt, since the suite named the exact function, but the cell that was supposed to prove the mutation applied proved nothing. Re-done with single quotes. This is the same trap already written down for this repo, hit by me, in a cell whose only purpose was to guard against exactly this.

One thing I checked that no test covers: the main flow's `HAD_OLD_PID=0; [ -n "$OLD_PID" ] && HAD_OLD_PID=1` runs under `set -euo pipefail`, and on a cold start the test fails. Sourcing stops before the main flow, so no behavioural test reaches that line. If `set -e` fired there, every cold start would abort before the health checks. It does not: `set -e` exempts the left side of an `&&` list, confirmed by running it under both shells — `survived, HAD_OLD_PID=0` on 3.2.57 and on 5.3.9. Safe, but it is untested main-flow wiring, which is the same class as #528's item 1 and belongs on that list.

On the `n/a` fourth state, which the worker flagged for a reviewer's judgment rather than quietly keeping: accepted, and it is in scope. The ticket asked for a third state because a sentinel conflating "no" with "cannot tell" hides two causes needing opposite handling. "The question does not apply" is a third such cause, not a variant of "cannot tell". Without it, the new warning would fire on every clean cold start, and a warning that cries wolf on the most common path trains the operator to skip it — which destroys the absence signal just as surely as putting the completion line in a `finally` would. The worker also proved the gate is actually consulted, using a cold-start fixture whose content deliberately looks like a died drain, so the test would fail if the gate were skipped. That is the right way to test a gate.

Both remaining outcomes are correctly excluded from the "no ERROR lines since restart" summary: only `complete` and `n/a` let it print.

scripts/redeploy-fleetd.sh

@@ -42,6 +42,14 @@
 #   8. fleetd #492 — a post-restart check counts running fleetd processes and fails the whole run if
 #      more than one is alive. That is the one thing none of the checks above (healthz 200, jar id,
 #      the fresh "listening" line) can see: every one of them is satisfied by EITHER daemon.
+#   9. fleetd #512 — the ERROR-line count above is blind by construction to the exact failure #493
+#      is about: an uncaught exception in a shutdown thread never passes through the logger, so it
+#      never carries an ERROR (or SEVERE) token that any count could see. This script now also
+#      greps the previous daemon's shutdown window for that exception's real shape, and separately
+#      asserts that SessionManager's drain-complete line (fleetd #522) is present there — its
+#      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.
 #
 # Usage:
 #   scripts/redeploy-fleetd.sh              # build, confirm, restart, verify
@@ -492,6 +500,114 @@ classify_amqp_connection_errors() {
   REDEPLOY_UNEXPLAINED_ERRORS=$((REDEPLOY_UNEXPLAINED_ERRORS + pending_inbox + pending_lead_mailbox))
 }
 
+# fleetd #512 part 2 — the negative check. #493's failure (an uncaught exception in a shutdown
+# thread) never passes through the logger: the JVM's default uncaught-exception handler prints
+# straight to stderr, so the line never carries a level, so classify_amqp_connection_errors's
+# ERROR/SEVERE token scan is structurally blind to it — measured on two hosts, including one where
+# even a syslog PRIORITY filter is blind to it too (fd 1 and fd 2 collapse to one socket there, so
+# every uncaught-exception line lands at priority 6/info). The fix is to grep the shape instead of
+# the level: `Exception in thread` at the start of a line (the handler's own banner) or
+# `NoClassDefFoundError` anywhere in it (the one real instance seen so far, but not the only shape
+# this could take). Kept as its own function, never folded into classify_amqp_connection_errors —
+# this is not an AMQP concern, and the two must stay independently readable and independently
+# testable.
+#
+# Sets REDEPLOY_UNCAUGHT_EXCEPTION_COUNT (lines matched) and REDEPLOY_UNCAUGHT_EXCEPTION_SAMPLE
+# (the first matching line, "" if none) so a caller can report both a count and a concrete quote
+# without re-reading the file. Pure: reads $1, sets globals, no side effects.
+scan_uncaught_exceptions() {
+  local log_file="$1" line
+  REDEPLOY_UNCAUGHT_EXCEPTION_COUNT=0
+  REDEPLOY_UNCAUGHT_EXCEPTION_SAMPLE=""
+  while IFS= read -r line || [ -n "$line" ]; do
+    case "$line" in
+      'Exception in thread'*|*NoClassDefFoundError*)
+        REDEPLOY_UNCAUGHT_EXCEPTION_COUNT=$((REDEPLOY_UNCAUGHT_EXCEPTION_COUNT + 1))
+        [ -n "$REDEPLOY_UNCAUGHT_EXCEPTION_SAMPLE" ] || REDEPLOY_UNCAUGHT_EXCEPTION_SAMPLE="$line"
+        ;;
+    esac
+  done < "$log_file"
+}
+
+# fleetd #512 part 2 — the positive check. fleetd #522 added a `log.info` at the very end of
+# SessionManager.drainAll's normal path (never in a `finally` — see the ticket discussion for why
+# that distinction matters): "drain complete: released=N abandoned=M (still BUSY at the shutdown
+# deadline)", printed once, on every successful drain, including the all-zero case. A drain that
+# dies partway through never reaches that statement, so the line's ABSENCE is a real signal — unlike
+# the ERROR-count check above, this one does not depend on the failure happening to throw.
+#
+# Sets REDEPLOY_DRAIN_COMPLETE_LINE to the matching line (last one, though drainAll runs at most
+# once per shutdown so there should never be more than one) or "" if absent. Pure, same shape as
+# scan_uncaught_exceptions above.
+find_drain_complete_line() {
+  local log_file="$1"
+  REDEPLOY_DRAIN_COMPLETE_LINE="$(grep -F 'drain complete: released=' "$log_file" | tail -1 || true)"
+}
+
+# fleetd #512 part 2 — THE TRAP, and the reason this is one function instead of two independent
+# checks the caller ORs together. Absence of the drain-complete line has TWO causes that need
+# OPPOSITE handling, and a naive "line absent -> the drain died" reading collapses them exactly the
+# way this whole ticket exists to stop: the line is emitted by the daemon being STOPPED, which is
+# running the OLD jar. Until a redeploy has landed fleetd #522 once, every previous daemon predates
+# the line and cannot emit it no matter how cleanly it drained — so on the very first redeploy after
+# #522 merged, "absent" means "too old to know how", not "died". Only once BOTH signals — this
+# line's absence AND scan_uncaught_exceptions' result — have been read together can the three real
+# outcomes be told apart:
+#
+#   complete -> the line is present: the drain finished. Name the counts it reported.
+#   died     -> the line is absent AND an uncaught-exception shape was found: the drain died. Name
+#               what was found.
+#   unknown  -> the line is absent AND no exception shape either: cannot tell. Say so, and say why
+#               (predates the line, or failed without throwing) — never worded as a pass or a
+#               failure, and never reassuring: "ok, no ERROR lines" one level up is the exact mistake
+#               this ticket exists to fix, and this outcome must not reproduce it.
+#
+# A fourth case, n/a, covers a cold start or a "loaded but wasn't running" restart: no previous
+# daemon was actually stopped THIS run, so there is no shutdown window in $log_file to have an
+# opinion about at all — scanning it anyway would read the NEW daemon's own startup lines and could
+# misreport "cannot tell" on every clean cold start. had_previous_daemon carries that fact in from
+# the caller (it already knows $OLD_PID) rather than this function re-deriving it from log content.
+#
+# Same shape as swap_if_built/refuse_drain_gate (fleetd #521/#528): the decision (which of the four
+# outcomes applies) and the action (which ok/warn line to print, and setting REDEPLOY_DRAIN_STATE
+# for the "result" section below to consult) live together in ONE function that the main flow calls
+# unconditionally — there is no guard left in the main flow to remove, invert, or bypass
+# independently of this function. Never calls die(): #512's own decision is to warn loudly and let
+# the redeploy stand, because by the time this is detectable the new daemon is already up and
+# healthy and failing here would give the operator nothing to do differently.
+report_shutdown_drain() {
+  local log_file="$1" had_previous_daemon="$2"
+  REDEPLOY_UNCAUGHT_EXCEPTION_COUNT=0
+  REDEPLOY_UNCAUGHT_EXCEPTION_SAMPLE=""
+  REDEPLOY_DRAIN_COMPLETE_LINE=""
+
+  if [ "$had_previous_daemon" != 1 ]; then
+    REDEPLOY_DRAIN_STATE="n/a"
+    ok "no previous daemon was running before this restart — nothing to check for a died shutdown drain"
+    return 0
+  fi
+
+  find_drain_complete_line "$log_file"
+  scan_uncaught_exceptions "$log_file"
+
+  if [ -n "$REDEPLOY_DRAIN_COMPLETE_LINE" ]; then
+    REDEPLOY_DRAIN_STATE="complete"
+    ok "previous daemon's shutdown drain finished: $REDEPLOY_DRAIN_COMPLETE_LINE"
+  elif [ "$REDEPLOY_UNCAUGHT_EXCEPTION_COUNT" -gt 0 ]; then
+    REDEPLOY_DRAIN_STATE="died"
+    warn "previous daemon's shutdown drain DIED — no drain-complete line, and an uncaught exception"
+    warn "was found in its shutdown window ($REDEPLOY_UNCAUGHT_EXCEPTION_COUNT line(s)):"
+    warn "    $REDEPLOY_UNCAUGHT_EXCEPTION_SAMPLE"
+    warn "Some sessions from the PREVIOUS daemon may not have been released."
+  else
+    REDEPLOY_DRAIN_STATE="unknown"
+    warn "cannot tell whether the previous daemon's shutdown drain finished — no drain-complete line"
+    warn "and no uncaught-exception shape either. This is NOT a pass and NOT a failure: it means"
+    warn "either that daemon predates fleetd #522's drain-complete log line, or its drain failed"
+    warn "without throwing (hung, or returned early)."
+  fi
+}
+
 # fleetd #517: extracted so the suite can call this decision directly, the same way #510 extracted
 # wait_for_daemon_exit so its ordering became checkable. Before this, the only test of the drain-gate
 # abort message was a grep of this script's own source for the wording — so mutating the `if` below
@@ -902,6 +1018,14 @@ trap 'rm -f "$FRESH_LOG"' EXIT
 tail -n "+$((RESTART_MARK + 1))" "$OUT" > "$FRESH_LOG" 2>/dev/null || true
 classify_amqp_connection_errors "$FRESH_LOG"
 
+# fleetd #512 part 2: the previous daemon's shutdown drain, checked in the same fresh-log region —
+# see report_shutdown_drain above for the full decision (four outcomes, one of them a deliberate
+# "cannot tell"). HAD_OLD_PID crosses in whether a previous daemon was actually stopped this run;
+# see the function's own comment for why that matters.
+say "previous daemon's shutdown drain"
+HAD_OLD_PID=0; [ -n "$OLD_PID" ] && HAD_OLD_PID=1
+report_shutdown_drain "$FRESH_LOG" "$HAD_OLD_PID"
+
 # fleetd #492: checked here, after healthz and the fresh-log check have both had time to run, so a
 # supervisor that revives the OLD jar a few seconds late is caught too. Every check above (healthz
 # 200, jar id, the fresh 'listening' line) is satisfied by EITHER daemon if two are alive — this is
@@ -911,7 +1035,14 @@ assert_single_daemon "$(running_pid)"
 say "result"
 ok "pid $NEW_PID, jar $(jar_id)"
 if [ "$REDEPLOY_ERROR_COUNT" -eq 0 ]; then
-  ok "no ERROR lines since restart"
+  # 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
+  # with, so this count alone cannot see that failure). "complete" and "n/a" are the only two
+  # outcomes report_shutdown_drain sets that mean nothing is wrong there.
+  if [ "$REDEPLOY_DRAIN_STATE" = "complete" ] || [ "$REDEPLOY_DRAIN_STATE" = "n/a" ]; then
+    ok "no ERROR lines since restart"
+  fi
 elif [ "$REDEPLOY_UNEXPLAINED_ERRORS" -eq 0 ]; then
   ok "$REDEPLOY_RECOVERED_AMQP_ERRORS AMQP connection reset ERROR lines recovered since restart"
 else