Compare commits

...

12 Commits

Author SHA1 Message Date
Dai Ha 36870836aa fleetd #505: a herdr error during the pane scan must not read as a clean negative
CI / contract (pull_request) Successful in 1m26s
CI / build (pull_request) Successful in 1m29s
A transient herdr error on pane.process_info during PaneLocator's pid→pane scan used
to be swallowed into a plain "does not own it", so a real worker whose owning pane
errored mid-scan resolved with a null terminal but a resolved (real) pid — exactly
what CallerResolver's loopback-trust fallback reads as the primary. That is a
worker→primary privilege escalation through the door fleetd #317 did not close: #317
guards a failed lsof lookup (c.resolved()), not a failed herdr pane scan.

Fix: add a third state to the scan instead of widening Caller.resolved() (which stays
centralised next to the lsof sentinel it tests, per #505's explicit instruction not
to reopen that decision). PaneLocator.terminalForPid now returns a Lookup(terminal,
complete) record: a HerdrException on one pane marks that pane's ownership UNKNOWN,
not DOES_NOT_OWN, and the scan is complete only if every pane was either matched or
confirmed not to own the pid. A definite match found elsewhere in the same scan
still short-circuits as complete — a pane that genuinely vanished mid-scan without
being the caller's own does not turn into a refusal.

ConnectionIdentity.Caller carries the new scanComplete flag alongside the unchanged
resolved(). CallerResolver's loopback-trust fallback now requires both resolved()
and scanComplete() before promoting to Principal.primary(); an incomplete scan
resolves anonymous, which fails toward the recoverable error (a refused primary
retries loudly; a promoted worker would not).

Logs a warning naming the pane and which herdr client (of how many) failed, so the
incomplete-scan path is diagnosable rather than silent (fleetd #317's own lesson).
2026-09-12 10:27:42 +07:00
ltms 136312fb11 Merge #503: Injector's readiness-grace warn prints measured elapsed time, never arithmetic on constants (fleetd #501)
CI / build (push) Successful in 1m28s
CI / contract (push) Successful in 1m27s
Verified by the lead, not taken from the worker's report.

Trial-merged onto main (4f28da6) and built the merge, because a clean auto-merge is not a compiling
merge:
  mvn clean install -> Tests run: 1689, Failures: 0, Errors: 0, Skipped: 0, BUILD SUCCESS
  InjectorTest -> Tests run: 34, Failures: 0
  Gitea CI on ac351ee: success

The worker mutated the two log arguments. I mutated the half it did not: the STAMP SITE. Changing
the first-sample guard so the clock is re-stamped on every non-ready poll gave 1 failure,
InjectorTest.readinessGraceExpiryLogsTheMeasuredElapsedTimeNotArithmeticOnConstants, on a clock-read
counter assertion: "the readiness-not-ready branch should read the clock exactly twice — once to
stamp the first non-ready sample, once at grace expiry". Two greps proved the mutant applied;
restored, shasum byte-identical, control 34/0 green.

Behaviour preserved: the restructure from `else if (p != null && ++t.notReadySincePoll >= N)` to a
nested `else if (p != null) { ... }` keeps the short-circuit, so the counter still increments only
when p != null. All three reset sites now clear notReadySinceMillis alongside notReadySincePoll.

Two notes for the record, neither a blocker.

The poll-count half is an equivalent mutant and the worker said so instead of reporting a kill it
did not get. That is the right call and the code comment states the limit honestly.

The clock is injected through a package-private constructor overload while the public constructors
default it to System::currentTimeMillis. My brief prescribed that shape. With exactly one production
construction site (Fleetd.java:531) a required parameter — fleetd #415's antidote — would have been
just as cheap and would match LeadRollover and the new Fleetd.awaitHerdr. The silent-survivor risk
#415 names is not present here, because the field is final and both public constructors delegate, so
a future constructor cannot compile without supplying it. Recording the choice so the next person
does not read it as an oversight.
2026-09-12 05:07:35 +02:00
ltms 4f28da62a3 Merge #499: redeploy-fleetd.sh gains an "unclear" supervisor state that cannot reach kill, and the detail survives the subshell (fleetd #492, #497)
CI / contract (push) Successful in 1m12s
CI / build (push) Successful in 1m32s
Two commits, b17f37a and 599419f. Verified by the lead, not taken from the worker's report.

b17f37a adds the fifth answer "unclear" for installed-but-not-loaded and for a probe that could not
answer at all, and makes require_drivable_supervisor die on it.

599419f fixes a defect I found in b17f37a: SUPERVISOR_UNCLEAR_DETAIL was set inside
detect_supervisor, which is called as $(detect_supervisor). A subshell only returns stdout, so the
detail never reached the caller, and a ${VAR:-generic} fallback then printed a message naming no
supervisor and no reason. Measured before the fix: plain call -> detail length 142; via $( ) ->
length 0.

Lead verification of the fix, re-running my own original measurement across every branch:

  launchd installed, not loaded   kind=[unclear]   detail_len=142
  systemd installed, not active   kind=[unclear]   detail_len=146
  launchd loaded (normal)         kind=[launchd]   detail_len=0
  systemd loaded (normal)         kind=[systemd]   detail_len=0
  neither -> none                 kind=[none]      detail_len=0
  both loaded -> ambiguous        kind=[ambiguous] detail_len=0

The separator is always emitted, so the ${RAW#*SEP} unpack cannot silently fall back to the whole
string on the four branches that carry no detail.

Harness proof, run by me: making detect_supervisor print the kind alone (two greps proved the mutant
applied) turned the suite red, exit 1, "FAIL: detail does not name the systemd unit it found
installed-but-not-loaded". Restored, shasum byte-identical, control exit 0, bash -n clean on both
files. 23 test functions defined, 23 invoked.

The three case "$SUPERVISOR_KIND" switches now have final arms, chosen by what each caller does with
the value: the reporting switch warns and continues (a diagnostic that aborts goes silent exactly
when the state is novel), while stop and start die.

Not fixed here, filed separately: the "was already not running" branches at :603 and :610 swallow a
failed launchctl unload / systemctl stop with || true and then print "ok" unconditionally.
2026-09-12 05:04:04 +02:00
ltms 708f1795ad Merge #502: awaitHerdr reports three outcomes with measured elapsed time, not one boolean (fleetd #498)
CI / contract (push) Successful in 58s
CI / build (push) Successful in 1m49s
Verified by the lead, not taken from the worker's report.

Trial-merged onto main (8f59019) locally and built the merge, because a clean auto-merge is not a
compiling merge:
  mvn clean install -> Tests run: 1687, Failures: 0, Errors: 0, Skipped: 0, BUILD SUCCESS
  FleetdAwaitHerdrTest -> Tests run: 6, Failures: 0
  Gitea CI on 274afaf: success

The worker mutated the three return values. I mutated the half it did not: the reap DECISION at the
call site. Changing logHerdrWaitOutcomeAndShouldReap to return true for INTERRUPTED gave 1 failure,
FleetdAwaitHerdrTest.interruptedLogsItsOwnMessageAndNeverClaimsTheBudgetElapsed:135 ("an interrupted
wait must not tell main to reap"). Two greps proved the mutant applied; restored, shasum
byte-identical, control 6/0 green.

Behaviour preserved: herdrUp is still true only for ANSWERED, and both its readers (the orphan reap
at :276 and the lead auto-launch gate at :375) see exactly what they saw before.

One correction to the worker's report, which changes nothing in the code. It wrote that a real
interrupt-detection regression "would also hang the daemon's startup thread forever". It would not:
in production `nanos` is System::nanoTime, so the deadline check still fires. The hang it hit was a
test-fixture property — a frozen injected clock with no iteration bound. That is fleetd #486's
shape, now seen in a second class, and it is recorded there.
2026-09-12 05:01:02 +02:00
Dai Ha 599419f9e6 fleetd #492 follow-up: carry the unclear detail across detect_supervisor's subshell boundary
CI / contract (pull_request) Successful in 47s
CI / build (pull_request) Successful in 1m53s
b17f37a set SUPERVISOR_UNCLEAR_DETAIL as a global inside detect_supervisor, but the real call
site invokes it as $(detect_supervisor) — a subshell — so that global died with the subshell and
the die() message's ${VAR:-fallback} silently masked the loss with generic text.

- detect_supervisor now packs kind and detail onto its one stdout line (joined by the ASCII unit
  separator byte, $SUPERVISOR_DETAIL_SEP), the only channel that survives $( ). The real call site
  unpacks both with in-shell parameter expansion — no extra subshell.
- Dropped the ${SUPERVISOR_UNCLEAR_DETAIL:-...} fallback at the die() message: under set -u, a
  missing detail now fails loudly instead of silently defaulting (same defect class as #497).
- Added a constraints comment block above detect_supervisor for future callers: stdout-only,
  no ${VAR:-default} papering over a lost value, and every case on the return value needs an
  explicit *) arm.
- Added *) arms to the three `case "$SUPERVISOR_KIND"` switches (report/stop/start): report warns
  and continues (display-only), stop/start die naming the value (they act on it).
- Rewrote the "unclear" test to go through the real call-site shape ($(detect_supervisor) then
  the same split), not a hand-constructed value, and tightened its final assertion to check for
  the actual detail text rather than $SYSTEMD_UNIT alone (the die() boilerplate names the unit
  either way, so that check could pass on a lost value).
2026-09-12 09:58:45 +07:00
Dai Ha ac351ee1de fleetd #501: readiness-grace expiry logs measured elapsed time and the loop's own poll counter, never the configured budget
CI / contract (pull_request) Successful in 49s
CI / build (pull_request) Successful in 2m2s
The line at Injector.java:383-387 printed two numbers that read as measurements
but were both compile-time constants: READINESS_GRACE_POLLS for the poll count
(the loop's own Target.notReadySincePoll counter was in scope at the same call
site), and READINESS_GRACE_POLLS * POLL_INTERVAL_MILLIS / 1000 for the elapsed
time — arithmetic on two constants, never a measurement, and wrong in the
direction that says everything ran on schedule.

Fix, copying the LongSupplier-clock shape LeadRollover already uses:
- print t.notReadySincePoll instead of the constant for the poll count (the two
  agree by construction on this branch, so no test can tell them apart — the
  comment says so honestly).
- add Target.notReadySinceMillis, stamped at the first non-ready sample and
  reset at all three sites notReadySincePoll already resets (:304, :355, :389
  pre-fix line numbers), to compute a real elapsed time at expiry.
- inject a LongSupplier nowMillis (defaulting to System::currentTimeMillis)
  through new package-private constructor overloads so a test can supply a
  clock whose advance does not track POLL_INTERVAL_MILLIS.

Tests use a ListAppender to assert on the log message contents, per
LeadRolloverTest's pattern. The elapsed-time test drives the loop with a stub
clock returning two literal, non-derived values so it can fail if the fix
regresses to the constant-arithmetic line — proved by mutation: reverting the
elapsed calculation to READINESS_GRACE_POLLS * POLL_INTERVAL_MILLIS turns that
one test red (1 failure); reverting the poll-count print to the constant is an
equivalent mutant (0 failures), because the counter and the constant are
identical at that exact call site by construction.

fleetd clean install: Tests run: 1683, Failures: 0, Errors: 0, Skipped: 0.
2026-09-12 09:57:57 +07:00
Dai Ha 274afafde6 fleetd #498: awaitHerdr distinguishes deadline-passed from interrupted, with measured elapsed time
CI / contract (pull_request) Successful in 51s
CI / build (pull_request) Successful in 1m51s
- awaitHerdr now returns a HerdrAwaitOutcome(HerdrWaitResult, elapsedNanos) instead of a bare
  boolean, so 'the wait budget genuinely ran out' and 'the waiting thread was interrupted' are
  two distinct, named states instead of the same false (fleetd #497's shape).
- awaitHerdr takes the clock (LongSupplier) and the per-poll sleep (Runnable) as required
  parameters, with no defaulted overload (fleetd #415), so a test can drive it.
- The startup call site is extracted into logHerdrWaitOutcomeAndShouldReap, since main() itself
  cannot be driven from a unit test; it logs a distinct message per outcome, always printing the
  measured elapsed time next to the configured budget, never the budget alone.
- Adds FleetdAwaitHerdrTest covering the seam (all three outcomes, plus the preserved interrupt
  flag) and the call site (the three distinct log messages), using ListAppender.
2026-09-12 09:54:59 +07:00
ltms 8f59019305 Merge #496: lead-rollover logs measured elapsed time and measured counts, never the configured budget (fleetd #494)
CI / contract (push) Successful in 1m14s
CI / build (push) Successful in 2m1s
Three commits. All verified by the lead in a detached worktree, not taken from the worker's report.

3fb3311 — the /clear-settle and success paths return measured elapsed time and a real nudge count
c87cc25 — print the measured nudge count; fix the same defect on the sibling turn-settle timeout line
e966cba — the poll count on the same line was still a constant; the test could not tell the difference

Lead verification at e966cba:
  mvn clean install -> Tests run: 1681, Failures: 0, Errors: 0, Skipped: 0, BUILD SUCCESS
  LeadRolloverTest  -> Tests run: 33, Failures: 0, Errors: 0, Skipped: 0
  Gitea CI on e966cba: success

Mutation M2 (PICKUP_GRACE_POLLS 8 -> 5), run by the lead: 2 failures,
clearGraceReleaseLogIsWarnWithMeasuredElapsed and successLogPrintsMeasuredElapsedForTheWholeRoll.
The emitted line under the mutant read "after 5 consecutive IDLE/DONE polls (4 of those were
nudged)", so both numbers now follow the loop. Restored, shasum byte-identical, control 33/0 green.

Known and deliberate limit, stated in the code comment: on the grace-release branch both counters
equal the constants by construction (one write site each), so no test can prove the difference on
that line. The change buys one source of truth, not provable coverage. The place nudges genuinely
varies with the run is the /clear-timeout warn, which is covered by a discriminating test.
2026-09-12 04:44:10 +02:00
Dai Ha e966cbadf9 fleetd #494 follow-up (2nd pass): the grace-release line still had one constant, and its test could not tell the difference
CI / contract (pull_request) Successful in 1m26s
CI / build (pull_request) Successful in 1m55s
Two more fixes on the same line, LeadRollover.java:600-624:

1. The poll-count argument (second, was PICKUP_GRACE_POLLS) now prints the
   loop's own idlePollsAwaitingPickup counter instead of the constant. Same
   defect shape as the nudges fix from c87cc25, one argument over.

2. LeadRolloverTest's clearGraceReleaseLogIsWarnWithMeasuredElapsed asserted
   its nudge-count expectation as `LeadRollover.PICKUP_GRACE_POLLS - 1` — the
   same expression the production code used to build the log line from, so it
   could not discriminate a reverted fix. Rewritten to plain literals
   ("after 8 consecutive IDLE/DONE polls (7 of those were nudged)"), proven to
   trip when PICKUP_GRACE_POLLS's value changes (2 failures under a
   PICKUP_GRACE_POLLS=5 mutation: this test and successLogPrintsMeasured...).

Also corrected the comment above the log line: idlePollsAwaitingPickup and
nudges each have exactly one write site on this loop's release branch, so they
cannot differ from PICKUP_GRACE_POLLS / PICKUP_GRACE_POLLS - 1 at this call
site — confirmed by re-deriving the loop's control flow, and by reverting just
the nudges argument (M1) and observing 33/0 stayed green even after the test
rewrite. That is an equivalent mutant on this line, not a gap the test rewrite
could close; the honest value of printing the counters is one source of truth
for the loop, not a provable-by-test difference here. The place nudges truly
varies with the run — and is covered by a test that can tell it apart from a
constant — is the /clear-timeout warn's clearResult.nudges() in runRollover.

mvn -Dtest=LeadRolloverTest test: 33/0. mvn clean install: 1681/0, BUILD SUCCESS.

Same-shape sweep (found, not fixed, per instructions):
Injector.java:383-387 — the readiness-grace warn prints the constant
READINESS_GRACE_POLLS where the measured per-target counter
t.notReadySincePoll is in scope (single increment site, just reached the
threshold at this call site — same equivalent-mutant situation as this fix).
2026-09-12 09:39:39 +07:00
Dai Ha b17f37a683 fleetd #492 follow-up: detect_supervisor must never read "could not tell" as "none"
CI / contract (pull_request) Successful in 1m11s
CI / build (pull_request) Successful in 1m32s
Two situations were silently landing in the "none" answer, which
require_drivable_supervisor accepts and the script then falls back to a raw
kill + nohup — exactly the wrong move when a supervisor actually IS present:

- installed-but-not-loaded, on either supervisor. `systemctl --user is-active`
  answers "no" for activating/deactivating/failed and while an auto-restart is
  pending too, and every one of those is a host that IS under systemd (or
  launchd) and about to act again. `*_installed` already knew this; it was
  only ever consulted for a warning line, never by the decision itself.
- a systemd probe that could not answer at all (e.g. systemctl cannot reach
  the user bus over a non-lingering ssh session) looked identical to a clean
  negative, because both probes redirected stderr straight to /dev/null.

detect_supervisor now returns a fifth answer, "unclear", for both cases.
systemd_loaded/systemd_installed capture systemctl's exit status and stderr
separately and set their own *_ERRORED flag only on a real tool failure
(non-zero exit WITH stderr), never on a clean negative. "none" now means only:
neither supervisor installed, neither loaded, neither probe errored.
require_drivable_supervisor die()s on "unclear" exactly like it already does
on "ambiguous", naming the specific supervisor and reason via the new
SUPERVISOR_UNCLEAR_DETAIL global.

Tests: 4 new cases (systemd/launchd installed-but-not-loaded, a real
systemd_loaded run through a systemctl stub that errors on stderr, and the
die() refusal for "unclear" naming the unit). All 3 new guards were verified
by mutation: each was removed from the real script, the suite caught it (a
new FAIL line naming the exact broken assertion), then the file was restored
byte-identically and the suite went green again.
2026-09-12 09:23:21 +07:00
Dai Ha c87cc25aa6 fleetd #494 follow-up: print the measured nudge count, and fix the sibling turn-settle timeout line
CI / contract (pull_request) Successful in 1m13s
CI / build (pull_request) Successful in 1m30s
- waitForClearPickupAndSettle's grace-release warn now prints the measured 'nudges' counter
  instead of the constant PICKUP_GRACE_POLLS - 1. The two happen to agree today, but the
  constant expression was wrong once before (printed PICKUP_GRACE_POLLS itself, claiming 8
  nudges where 7 went out) and a code read did not catch it — only a mutation test did.
  Printing the counter cannot drift from the loop's real behaviour.
- waitUntilAtTurnBoundary (the FIRST wait, ~line 386-391) had the identical 'configured value
  printed as if measured' defect as the three lines fixed in the original #494 commit, but was
  out of scope because the brief named specific lines instead of the shape. Fixed the same way:
  it now returns a TurnSettleResult(settled, elapsedMillis) instead of a bare boolean, and the
  timeout warn prints 'configured={}s elapsed={}ms' instead of presenting cfg.turnSettleSeconds()
  as the measured wait.
- No behaviour change: same sends, same order, same release/refuse decisions.
- Test additions: clearGraceReleaseLogIsWarnWithMeasuredElapsed now also asserts the measured
  nudge count; successLogPrintsMeasuredElapsedForTheWholeRoll's expected elapsed value is
  updated (7000ms, not 6500ms) to account for waitUntilAtTurnBoundary's own new clock read; a
  new turnTimeoutLogPrintsMeasuredElapsedNotJustConfigured test pins the sibling line.
- Proved the nudges fix with a temporary mutation: set PICKUP_GRACE_POLLS to 5, confirmed via
  two greps that the mutant applied and the original constant was gone, ran the grace-release
  test and read the actual log line — nudge count followed to 4 (= 5 - 1), then restored to 8
  and reran the full LeadRolloverTest suite as a control (33/33 green).
2026-09-12 09:22:19 +07:00
Dai Ha 3fb331145a fleetd #494: log measured elapsed time, never the configured budget, on a lead-rollover failure/success
CI / contract (pull_request) Successful in 52s
CI / build (pull_request) Successful in 1m35s
- runRollover's /clear-timeout warn now prints configured/elapsed/nudges, each labelled,
  instead of presenting cfg.clearSettleSeconds() as if it were the measured wait.
- waitForClearPickupAndSettle's pickup-grace release is now log.warn (was log.info) and
  prints the measured elapsed time next to the target pane — this is the exact path that
  reported a false-success roll in the real incident (438ms of a 20s budget).
- The success line ('lead-rollover: rolled') now prints the measured elapsed time for the
  whole roll.
- waitForClearPickupAndSettle now returns a ClearSettleResult(settled, elapsedMillis, nudges)
  instead of a bare boolean, so callers can log the measured values instead of the config.
- No behaviour change: same sends, same order, same release/refuse decisions.
- Adds 3 tests to LeadRolloverTest pinning the content of each changed log line, using a
  self-advancing fake clock so the measured elapsed/nudge values are deterministic and
  provably distinct from the configured budget.
2026-09-12 09:08:04 +07:00
16 changed files with 1280 additions and 122 deletions
+106 -18
View File
@@ -80,6 +80,7 @@ import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicReference;
import java.util.function.Function;
import java.util.function.LongSupplier;
import java.util.function.Predicate;
import java.util.function.Supplier;
import java.util.regex.Pattern;
@@ -270,15 +271,12 @@ public final class Fleetd {
// the first thing that actually talks to herdr, so without this wait a boot-order race
// would crash the daemon into a restart loop. Wait, then degrade rather than die: serving
// with /healthz reporting "degraded" is strictly more useful than exiting.
boolean herdrUp = awaitHerdr(herdr);
HerdrAwaitOutcome herdrOutcome = awaitHerdr(herdr, System::nanoTime, Fleetd::sleepHerdrPoll);
boolean herdrUp = logHerdrWaitOutcomeAndShouldReap(herdrOutcome);
if (herdrUp) {
// CB-117: herdr keeps worker panes alive across a daemon restart, and their ids died
// with the previous process — reap those leaked orphans now, before we start serving.
workers.reapOrphanWorkers();
} else {
log.warn("herdr did not answer within {}s — starting anyway; /healthz will report "
+ "degraded until it comes up. Orphaned worker panes (if any) were NOT reaped.",
HERDR_WAIT_SECONDS);
}
// CB-301: authoritative session registry + lifecycle FSM on top of ClaudeCodeLauncher.
@@ -1696,12 +1694,70 @@ public final class Fleetd {
}
/**
* Poll herdr's {@code ping} until it answers or {@link #HERDR_WAIT_SECONDS} elapses (CB-504).
*
* @return true if herdr answered, false if it never did
* How {@link #awaitHerdr} ended (fleetd #498). The old code returned a bare {@code boolean},
* which collapsed two different facts onto the same {@code false}: the configured wait budget
* genuinely running out, and the waiting thread being interrupted possibly milliseconds in.
* Those need different operator messages — see {@link #logHerdrWaitOutcomeAndShouldReap} — so
* this is a third state, not a better number (the same shape fleetd #497 named). Never treat
* {@link #INTERRUPTED} as if it were {@link #DEADLINE_PASSED}: only the latter means herdr was
* actually given the full {@link #HERDR_WAIT_SECONDS} and still failed to answer.
*/
private static boolean awaitHerdr(HerdrClient herdr) {
long deadline = System.nanoTime() + HERDR_WAIT_SECONDS * 1_000_000_000L;
enum HerdrWaitResult {
/** herdr answered {@code ping} before the deadline. */
ANSWERED,
/** the configured {@link #HERDR_WAIT_SECONDS} budget elapsed with no answer. */
DEADLINE_PASSED,
/**
* the waiting thread was interrupted before the budget ran out — a different event from
* {@link #DEADLINE_PASSED} and must never be reported as "did not answer within Ns".
*/
INTERRUPTED
}
/**
* The outcome of one {@link #awaitHerdr} call, carrying the MEASURED elapsed wait time
* alongside {@link #result}. {@code elapsedNanos} is always measured against the {@code nanos}
* supplier passed to {@link #awaitHerdr} — never assume it equals the configured budget, the
* same defect fleetd #494 already fixed once in {@code LeadRollover}.
*/
record HerdrAwaitOutcome(HerdrWaitResult result, long elapsedNanos) {}
/**
* The real per-poll wait {@link #main} passes to {@link #awaitHerdr}: sleep
* {@link #HERDR_WAIT_POLL_MILLIS}, and on interruption re-set the thread's interrupt flag
* rather than throwing — {@link #awaitHerdr} detects an interruption by checking {@link
* Thread#isInterrupted()} right after this returns, so a poller that swallowed the flag
* instead of restoring it would make that check silently miss the interruption.
*/
private static void sleepHerdrPoll() {
try {
Thread.sleep(HERDR_WAIT_POLL_MILLIS);
} catch (InterruptedException ie) {
Thread.currentThread().interrupt();
}
}
/**
* Poll herdr's {@code ping} until it answers, the configured {@link #HERDR_WAIT_SECONDS}
* budget elapses, or the waiting thread is interrupted (CB-504, fleetd #498).
*
* <p>{@code nanos} and {@code poller} are required parameters with no defaulted overload
* (fleetd #415's shape: a defaulted overload is a silent survivor a green suite would vouch
* for) — the previous version read {@link System#nanoTime()} and called {@link Thread#sleep}
* directly, so nothing could drive it from a test. The one production call site in {@link
* #main} passes {@code System::nanoTime} and {@link #sleepHerdrPoll}.
*
* @param nanos a monotonic elapsed-time clock, e.g. {@code System::nanoTime} — never a
* wall-clock source, since only elapsed time (not a timestamp) is measured here
* @param poller called once per failed ping while the budget remains; must, on an
* {@link InterruptedException}, re-set the thread's interrupt flag rather than
* throw or swallow it — this method's interruption check reads that flag right
* after {@code poller.run()} returns
* @return the outcome and the measured elapsed wait time — see {@link HerdrAwaitOutcome}
*/
static HerdrAwaitOutcome awaitHerdr(HerdrClient herdr, LongSupplier nanos, Runnable poller) {
long start = nanos.getAsLong();
long deadline = start + HERDR_WAIT_SECONDS * 1_000_000_000L;
boolean waited = false;
while (true) {
try {
@@ -1709,25 +1765,57 @@ public final class Fleetd {
if (waited) {
log.info("herdr is up");
}
return true;
return new HerdrAwaitOutcome(HerdrWaitResult.ANSWERED, nanos.getAsLong() - start);
} catch (HerdrException e) {
if (System.nanoTime() >= deadline) {
return false;
if (nanos.getAsLong() >= deadline) {
return new HerdrAwaitOutcome(HerdrWaitResult.DEADLINE_PASSED, nanos.getAsLong() - start);
}
if (!waited) {
log.info("waiting up to {}s for the herdr socket…", HERDR_WAIT_SECONDS);
waited = true;
}
try {
Thread.sleep(HERDR_WAIT_POLL_MILLIS);
} catch (InterruptedException ie) {
Thread.currentThread().interrupt();
return false;
poller.run();
if (Thread.currentThread().isInterrupted()) {
return new HerdrAwaitOutcome(HerdrWaitResult.INTERRUPTED, nanos.getAsLong() - start);
}
}
}
}
/**
* Log the right message for {@code outcome} — never the configured {@link #HERDR_WAIT_SECONDS}
* budget alone, always the measured elapsed time next to it — and say whether {@link #main}
* should now reap orphan worker panes (fleetd #498).
*
* <p>Extracted out of {@link #main} so this decision is drivable from a test: {@link #main}
* boots the whole daemon and cannot itself be run in a unit test, but this is the exact,
* unmodified code {@link #main} calls for the decision, not a re-derivation of it.
*
* @return true only for {@link HerdrWaitResult#ANSWERED} — orphan workers are reaped only
* then, exactly as before this ticket
*/
static boolean logHerdrWaitOutcomeAndShouldReap(HerdrAwaitOutcome outcome) {
long elapsedMillis = TimeUnit.NANOSECONDS.toMillis(outcome.elapsedNanos());
if (outcome.result() == HerdrWaitResult.ANSWERED) {
return true;
}
if (outcome.result() == HerdrWaitResult.DEADLINE_PASSED) {
log.warn("herdr did not answer within the configured wait (configured={}s elapsed={}ms) "
+ "— starting anyway; /healthz will report degraded until it comes up. Orphaned "
+ "worker panes (if any) were NOT reaped.",
HERDR_WAIT_SECONDS, elapsedMillis);
return false;
}
// HerdrWaitResult.INTERRUPTED — a different fact from DEADLINE_PASSED (fleetd #498): the
// wait was cut short, not exhausted, and must never be reported as "did not answer within
// Ns" — that claim would be false and would send an operator to debug herdr for nothing.
log.warn("herdr wait was interrupted before the configured wait ran out (configured={}s "
+ "elapsed={}ms) — starting anyway; /healthz will report degraded until it comes "
+ "up. Orphaned worker panes (if any) were NOT reaped.",
HERDR_WAIT_SECONDS, elapsedMillis);
return false;
}
private Fleetd() {
}
}
@@ -244,7 +244,15 @@ public final class CallerResolver {
// already names what happens if that case is handed the primary role: a worker→primary
// escalation. So an unresolved caller is refused (ANONYMOUS — the same clean, already-tested
// "authenticated as nothing" outcome used everywhere else in this method), never promoted.
return isLoopback(remoteAddr) && c.resolved() ? Principal.primary(c.pid()) : Principal.anonymous();
//
// fleetd #505: the OTHER way a real pid can wrongly reach here with a null terminal — not a
// failed lsof lookup, but a herdr error partway through PaneLocator's pane scan. c.resolved()
// says nothing about that; it only tests the lsof sentinel (by design — see
// ConnectionIdentity.Caller#resolved). c.scanComplete() is the separate signal: a scan that
// could not check every pane must not be read as "checked everywhere, no match" — the pane it
// could not check might have been the caller's own. So both must hold before this promotes.
return isLoopback(remoteAddr) && c.resolved() && c.scanComplete()
? Principal.primary(c.pid()) : Principal.anonymous();
}
private boolean presentedTokenMatches(String authorizationHeader) {
@@ -1,6 +1,8 @@
package dev.ltms.fleet.herdr;
import com.fasterxml.jackson.databind.JsonNode;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import java.util.LinkedHashSet;
import java.util.List;
@@ -36,6 +38,8 @@ import java.util.Set;
*/
public final class PaneLocator {
private static final Logger log = LoggerFactory.getLogger(PaneLocator.class);
/**
* Bound on how many ancestor generations {@link #ancestorsOf} walks. This runs on every MCP
* call, so a cycle or a pathologically deep process tree must not hang identity resolution;
@@ -73,22 +77,46 @@ public final class PaneLocator {
}
/**
* The {@code terminal_id} of the agent pane whose process tree contains {@code pid}, or
* {@code null} if no agent pane on any searched daemon owns it (e.g. the caller is the
* primary, or off-host).
* The outcome of a {@link #terminalForPid} scan: the {@code terminal_id} of the agent pane
* whose process tree contains the pid ({@link #terminal} is {@code null} if none matched),
* and whether the scan that produced that answer ran to completion on every daemon searched.
*
* <p>{@link #complete} is {@code false} exactly when some {@code pane.process_info} call
* failed and, despite that, no pane was ever found to own the pid. In that case a {@code null}
* {@link #terminal} means "could not tell", not "definitely not a worker" — fleetd #505: a
* transient herdr error on the very pane that <em>does</em> own the caller's pid must not read
* as a clean negative and fall through to {@code Principal.primary}, the same way #317's
* {@code Caller.resolved()} already guards a failed lsof lookup. Callers ({@code
* ConnectionIdentity}, {@code CallerResolver}) must refuse rather than promote on an incomplete
* scan.
*
* <p>When a pane genuinely owns the pid, {@link #complete} is {@code true} regardless of
* whether some other, unrelated pane failed to answer earlier in the same scan — a positive
* match is definitive and does not need every pane to have been checked (a pane that "vanished
* mid-scan" but was never the match is still a clean, complete result).
*/
public String terminalForPid(long pid) {
public record Lookup(String terminal, boolean complete) {
private static final Lookup NOT_FOUND = new Lookup(null, true);
}
/**
* Resolve {@code pid} to the agent pane whose process tree contains it, across every searched
* herdr daemon. See {@link Lookup} for how to read a {@code null} terminal.
*/
public Lookup terminalForPid(long pid) {
if (pid <= 0) {
return null;
return Lookup.NOT_FOUND;
}
Set<Long> ancestry = ancestorsOf(pid);
for (HerdrClient herdr : herdrs) {
String terminal = terminalForPid(herdr, ancestry);
if (terminal != null) {
return terminal;
boolean complete = true;
for (int i = 0; i < herdrs.size(); i++) {
Lookup outcome = scan(herdrs.get(i), i, herdrs.size(), ancestry);
if (outcome.terminal() != null) {
return outcome; // a definite match — no need to finish checking other clients
}
complete = complete && outcome.complete();
}
return null;
return new Lookup(null, complete);
}
/**
@@ -117,31 +145,51 @@ public final class PaneLocator {
return ancestry;
}
private static String terminalForPid(HerdrClient herdr, Set<Long> ancestry) {
/** Whether a pane owns one of the scanned pid's ancestors, or the check of it failed outright. */
private enum Ownership { OWNS, DOES_NOT_OWN, UNKNOWN }
private static Lookup scan(HerdrClient herdr, int clientIndex, int clientCount, Set<Long> ancestry) {
boolean complete = true;
for (JsonNode pane : herdr.call("pane.list", Map.of()).path("panes")) {
String paneId = pane.path("pane_id").asText(null);
if (paneId != null && paneOwnsAnyOf(herdr, paneId, ancestry)) {
return pane.path("terminal_id").asText(null);
if (paneId == null) {
continue;
}
Ownership owns = paneOwnsAnyOf(herdr, clientIndex, clientCount, paneId, ancestry);
if (owns == Ownership.OWNS) {
return new Lookup(pane.path("terminal_id").asText(null), true);
}
if (owns == Ownership.UNKNOWN) {
complete = false;
}
}
return null;
return new Lookup(null, complete);
}
private static boolean paneOwnsAnyOf(HerdrClient herdr, String paneId, Set<Long> ancestry) {
private static Ownership paneOwnsAnyOf(HerdrClient herdr, int clientIndex, int clientCount,
String paneId, Set<Long> ancestry) {
JsonNode info;
try {
info = herdr.call("pane.process_info", Map.of("pane_id", paneId)).path("process_info");
} catch (HerdrException e) {
return false; // pane vanished mid-scan — just skip it
// fleetd #505: this used to be read as a clean "does not own it" (the pane vanished
// mid-scan, just skip it) — one boolean carrying two different facts. It is UNKNOWN
// now: if THIS pane is the one that owns the pid, the caller must not be told "no pane
// owns it", because that reads as a real primary and is promoted under loopback-trust.
log.warn("pane.process_info failed for pane {} on herdr client {} of {} during a "
+ "pid-owner scan — treating it as \"could not tell\", not a clean "
+ "negative (fleetd #505): {}",
paneId, clientIndex + 1, clientCount, e.getMessage());
return Ownership.UNKNOWN;
}
if (ancestry.contains(info.path("shell_pid").asLong(-1))) {
return true;
return Ownership.OWNS;
}
for (JsonNode p : info.path("foreground_processes")) {
if (ancestry.contains(p.path("pid").asLong(-1))) {
return true;
return Ownership.OWNS;
}
}
return false;
return Ownership.DOES_NOT_OWN;
}
}
@@ -15,6 +15,7 @@ import java.util.Set;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.ConcurrentHashMap;
import java.util.function.Consumer;
import java.util.function.LongSupplier;
import java.util.function.Predicate;
import java.util.stream.Collectors;
@@ -94,6 +95,14 @@ public final class Injector {
private final TurnListener turnListener;
private final Predicate<String> ready; // CB-113: a target is deliverable only when available
private final Consumer<String> forget; // CB-114: clear a gone worker's readiness/presence
/**
* Wall-clock source for the readiness-grace elapsed time logged in {@link #onStatus} (fleetd
* #501). Production constructors default this to {@code System::currentTimeMillis}; the
* package-private constructors below take it explicitly so a test can supply a stub whose
* advance does not track {@link #POLL_INTERVAL_MILLIS} — copying the shape {@code LeadRollover}
* already uses for the same purpose.
*/
private final LongSupplier nowMillis;
private final ConcurrentHashMap<String, Target> targets = new ConcurrentHashMap<>();
/** Delivery only; completion signalling is a no-op and every target is treated as available. */
@@ -125,20 +134,34 @@ public final class Injector {
*/
public Injector(AgentControl agents, TurnListener turnListener, Predicate<String> ready,
Consumer<String> forget) {
this(agents, turnListener, ready, forget, System::currentTimeMillis);
}
/** Full constructor — for tests: an injectable wall-clock supplier (fleetd #501). */
Injector(AgentControl agents, TurnListener turnListener, Predicate<String> ready,
Consumer<String> forget, LongSupplier nowMillis) {
this.agents = agents;
this.router = null;
this.turnListener = turnListener;
this.ready = ready;
this.forget = forget;
this.nowMillis = nowMillis;
}
public Injector(HerdrRouter router, TurnListener turnListener, Predicate<String> ready,
Consumer<String> forget) {
this(router, turnListener, ready, forget, System::currentTimeMillis);
}
/** Full constructor — for tests: an injectable wall-clock supplier (fleetd #501). */
Injector(HerdrRouter router, TurnListener turnListener, Predicate<String> ready,
Consumer<String> forget, LongSupplier nowMillis) {
this.agents = null;
this.router = router;
this.turnListener = turnListener;
this.ready = ready;
this.forget = forget;
this.nowMillis = nowMillis;
}
private AgentControl agentsFor(String target) {
@@ -209,6 +232,7 @@ public final class Injector {
int unknownSinceTurn; // consecutive `unknown` samples while a delegation is outstanding (CB-109)
int unknownSincePostTurn; // the same, for the post-turn housekeeping phase (fleetd #306)
int notReadySincePoll; // consecutive injectable samples a queued message waited on the readiness gate (CB-114)
long notReadySinceMillis; // wall-clock time of the FIRST non-ready sample in the current notReadySincePoll streak (fleetd #501); reset alongside it
boolean postTurnPending; // completion observed; adapter housekeeping has not started yet
boolean awaitingPostTurnPickup;
boolean postTurnObserved;
@@ -302,6 +326,7 @@ public final class Injector {
t.unknownSinceTurn = 0;
t.unknownSincePostTurn = 0;
t.notReadySincePoll = 0;
t.notReadySinceMillis = 0;
if (t.awaitingCompletion) t.turnObserved = true;
} else if (status.injectable()) { // IDLE or BLOCKED
t.unknownSinceTurn = 0;
@@ -353,6 +378,7 @@ public final class Injector {
Pending p = t.queue.peek();
if (p != null && ready.test(target)) {
t.notReadySincePoll = 0;
t.notReadySinceMillis = 0;
try {
agentsFor(target).send(target, p.text());
t.queue.poll();
@@ -370,23 +396,52 @@ public final class Injector {
sent = p;
sendError = e;
}
} else if (p != null && ++t.notReadySincePoll >= READINESS_GRACE_POLLS) {
// The worker has been idle-but-not-ready for the whole grace: its Claude
// never connected the bridge MCP (crashed during boot, or wedged on a
// startup prompt). The readiness gate would hold this message forever, so
// fail every queued message and release the target (CB-114) instead of
// polling it indefinitely with the caller's future never completing.
notReady = new ArrayList<>(t.queue);
for (Pending pending : notReady) {
pending.state = Pending.State.NOT_DELIVERED;
} else if (p != null) {
// fleetd #501: stamp the wall-clock time of the FIRST non-ready sample in
// this streak, so the expiry log below can print how long the target
// actually sat non-ready — not just how many polls that took.
if (t.notReadySincePoll == 0) {
t.notReadySinceMillis = nowMillis.getAsLong();
}
if (++t.notReadySincePoll >= READINESS_GRACE_POLLS) {
// The worker has been idle-but-not-ready for the whole grace: its Claude
// never connected the bridge MCP (crashed during boot, or wedged on a
// startup prompt). The readiness gate would hold this message forever, so
// fail every queued message and release the target (CB-114) instead of
// polling it indefinitely with the caller's future never completing.
notReady = new ArrayList<>(t.queue);
for (Pending pending : notReady) {
pending.state = Pending.State.NOT_DELIVERED;
}
// fleetd #501: t.notReadySincePoll — the loop's own counter, already in
// scope — is printed here instead of the READINESS_GRACE_POLLS constant.
// On this branch the counter has JUST reached the threshold, so the two
// agree by construction and no test can tell them apart. Printed anyway:
// it gives this line one source of truth instead of two, so a later
// change to the loop above cannot leave this message reporting a number
// the loop no longer produces.
//
// elapsedMillis is a different case: it is NOT equal-by-construction to
// the truth. notReadySincePoll only increments on a sample that reaches
// this branch (p != null, not ready) — a poll that misses that condition
// advances real time without advancing the counter — and this loop's real
// period is not guaranteed to equal POLL_INTERVAL_MILLIS (load, or a host
// sleep, can widen the real gap far past it). READINESS_GRACE_POLLS *
// POLL_INTERVAL_MILLIS / 1000 is arithmetic on two constants, not a
// measurement, so it stays here only as the labelled CONFIGURED budget,
// never presented as elapsed time.
long elapsedMillis = nowMillis.getAsLong() - t.notReadySinceMillis;
log.warn("readiness grace for {} expired after {} polls (configured={} "
+ "polls/{}s elapsed={}ms): target never became "
+ "deliverable, so failing {} queued message(s) that "
+ "never reached its pane",
target, t.notReadySincePoll, READINESS_GRACE_POLLS,
READINESS_GRACE_POLLS * POLL_INTERVAL_MILLIS / 1000, elapsedMillis,
notReady.size());
t.queue.clear();
t.notReadySincePoll = 0;
t.notReadySinceMillis = 0;
}
log.warn("readiness grace for {} expired after {} polls ({}s): target never "
+ "became deliverable, so failing {} queued message(s) that never "
+ "reached its pane",
target, READINESS_GRACE_POLLS,
READINESS_GRACE_POLLS * POLL_INTERVAL_MILLIS / 1000, notReady.size());
t.queue.clear();
t.notReadySincePoll = 0;
}
}
}
@@ -381,13 +381,18 @@ public final class LeadRollover {
*/
private void runRollover(PendingRollover p, FleetConfig.LeadRollover cfg) {
String lead = p.leadTerminal();
boolean turnSettled = waitUntilAtTurnBoundary(lead, cfg.turnSettleSeconds());
if (!turnSettled) {
log.warn("lead-rollover: pane {} did not reach a turn boundary (IDLE or DONE) within {}s "
+ "after confirm() — refusing to send /clear at all; the calling lead's "
+ "own turn is still live and clearing it now would destroy live context "
+ "(token={})",
lead, cfg.turnSettleSeconds(), p.token());
long rollStartMillis = nowMillis.getAsLong();
TurnSettleResult turnResult = waitUntilAtTurnBoundary(lead, cfg.turnSettleSeconds());
if (!turnResult.settled()) {
// fleetd #494 follow-up: this line had the SAME defect as the /clear-timeout line below
// — cfg.turnSettleSeconds() is the CONFIGURED budget, not how long this wait actually
// ran. Print the measured elapsed time alongside it, labelled, exactly like the /clear
// path already does.
log.warn("lead-rollover: pane {} did not reach a turn boundary (IDLE or DONE) after "
+ "confirm() — refusing to send /clear at all; the calling lead's own "
+ "turn is still live and clearing it now would destroy live context "
+ "(token={}, configured={}s elapsed={}ms)",
lead, p.token(), cfg.turnSettleSeconds(), turnResult.elapsedMillis());
return;
}
@@ -395,15 +400,22 @@ public final class LeadRollover {
// /clear is housekeeping, not a delegated turn, and routing it through Injector wedges the
// pane forever (see this class's javadoc).
agents.send(lead, "/clear");
boolean clearSettled = waitForClearPickupAndSettle(lead, cfg.clearSettleSeconds());
if (!clearSettled) {
log.warn("lead-rollover: pane {} did not reach a turn boundary (IDLE or DONE) within {}s "
+ "after /clear — NOT sending bootstrapText (token={})",
lead, cfg.clearSettleSeconds(), p.token());
ClearSettleResult clearResult = waitForClearPickupAndSettle(lead, cfg.clearSettleSeconds());
if (!clearResult.settled()) {
// fleetd #494: cfg.clearSettleSeconds() is the CONFIGURED budget, not how long the wait
// actually ran — an operator reading only that number wrongly believes it is a measured
// duration. Print the measured elapsed time and nudge count alongside it, each labelled,
// so the two can be compared at a glance.
log.warn("lead-rollover: pane {} did not reach a turn boundary (IDLE or DONE) after "
+ "/clear — NOT sending bootstrapText (token={}, configured={}s "
+ "elapsed={}ms nudges={})",
lead, p.token(), cfg.clearSettleSeconds(), clearResult.elapsedMillis(),
clearResult.nudges());
return;
}
agents.send(lead, cfg.bootstrapTextFor(p.handoverPath()));
log.info("lead-rollover: rolled token={} lead={}", p.token(), lead);
long rollElapsedMillis = nowMillis.getAsLong() - rollStartMillis;
log.info("lead-rollover: rolled token={} lead={} elapsedMs={}", p.token(), lead, rollElapsedMillis);
}
/** Drop a pending request without rolling. @return whether a pending request existed for {@code token} */
@@ -475,9 +487,15 @@ public final class LeadRollover {
* gate exists to prevent. Do not "simplify" this back to {@code injectable()}. ({@link
* #waitForClearPickupAndSettle} keeps the same exclusion of {@code BLOCKED}, for the same
* reason, on the second wait.)
*
* @return a {@link TurnSettleResult} whose {@code settled()} is {@code true} once a real
* boundary was observed, {@code false} if {@code settleSeconds} elapses first.
* {@code elapsedMillis()} is a MEASURED value from the injected {@link #nowMillis}
* clock, never the configured {@code settleSeconds} budget (fleetd #494 follow-up).
*/
private boolean waitUntilAtTurnBoundary(String target, int settleSeconds) {
long deadline = nowMillis.getAsLong() + TimeUnit.SECONDS.toMillis(settleSeconds);
private TurnSettleResult waitUntilAtTurnBoundary(String target, int settleSeconds) {
long startMillis = nowMillis.getAsLong();
long deadline = startMillis + TimeUnit.SECONDS.toMillis(settleSeconds);
while (nowMillis.getAsLong() < deadline) {
AgentStatus status;
try {
@@ -488,13 +506,20 @@ public final class LeadRollover {
status = null;
}
if (status == AgentStatus.IDLE || status == AgentStatus.DONE) {
return true;
return new TurnSettleResult(true, nowMillis.getAsLong() - startMillis);
}
settleSleeper.run();
}
return false;
return new TurnSettleResult(false, nowMillis.getAsLong() - startMillis);
}
/**
* The measured outcome of {@link #waitUntilAtTurnBoundary} — fleetd #494 follow-up. The sibling
* of {@link ClearSettleResult} for the FIRST wait, which never nudges, so it carries no nudge
* count.
*/
private record TurnSettleResult(boolean settled, long elapsedMillis) {}
/**
* The SECOND wait in {@link #runRollover} — after {@code /clear} has been sent, waits for it to
* settle, bounded by {@code settleSeconds}. <strong>fleetd #489 — the paste-race fix.</strong>
@@ -524,8 +549,9 @@ public final class LeadRollover {
* Claude Code prompt is a no-op, so repeating it is safe;</li>
* <li>the {@code PICKUP_GRACE_POLLS}th consecutive such poll, with {@code WORKING} still never
* observed, releases rather than wedges the roll instead of nudging again — the same
* choice {@code Injector} makes — and returns {@code true} anyway, logged at {@code info}
* so an operator can see which path ran;</li>
* choice {@code Injector} makes — and returns {@code settled() == true} anyway, logged at
* {@code warn} with the measured elapsed time (fleetd #494) so an operator can see which
* path ran and how long it actually took;</li>
* <li>once {@code WORKING} has been observed, nudging stops and this instead waits for a real
* {@code working → IDLE/DONE} completion boundary before returning {@code true}.</li>
* </ul>
@@ -541,15 +567,20 @@ public final class LeadRollover {
* swallowed and logged at {@code debug}, exactly like {@code Injector.java:437-442} — a failed
* nudge must not abort the roll.
*
* @return {@code true} once {@code /clear} has settled, or once the nudge budget was exhausted
* with no pickup ever observed (released rather than wedged); {@code false} if {@code
* settleSeconds} elapses first — the caller must NOT send {@code bootstrapText} in that
* case, exactly as before this fix
* @return a {@link ClearSettleResult} whose {@code settled()} is {@code true} once {@code
* /clear} has settled, or once the nudge budget was exhausted with no pickup ever
* observed (released rather than wedged); {@code false} if {@code settleSeconds} elapses
* first — the caller must NOT send {@code bootstrapText} in that case, exactly as before
* this fix. {@code elapsedMillis()} and {@code nudges()} are MEASURED values (from the
* injected {@link #nowMillis} clock and an actual nudge count), never the configured
* {@code settleSeconds} budget (fleetd #494).
*/
private boolean waitForClearPickupAndSettle(String target, int settleSeconds) {
long deadline = nowMillis.getAsLong() + TimeUnit.SECONDS.toMillis(settleSeconds);
private ClearSettleResult waitForClearPickupAndSettle(String target, int settleSeconds) {
long startMillis = nowMillis.getAsLong();
long deadline = startMillis + TimeUnit.SECONDS.toMillis(settleSeconds);
boolean pickedUp = false; // a WORKING sample has been observed since /clear was sent
int idlePollsAwaitingPickup = 0;
int nudges = 0;
while (nowMillis.getAsLong() < deadline) {
AgentStatus status;
try {
@@ -563,26 +594,56 @@ public final class LeadRollover {
pickedUp = true;
} else if (status == AgentStatus.IDLE || status == AgentStatus.DONE) {
if (pickedUp) {
return true; // a real WORKING -> IDLE/DONE completion boundary
// a real WORKING -> IDLE/DONE completion boundary
return new ClearSettleResult(true, nowMillis.getAsLong() - startMillis, nudges);
}
if (++idlePollsAwaitingPickup >= PICKUP_GRACE_POLLS) {
log.info("lead-rollover: /clear on {} was never observed as WORKING after {} "
long elapsedMillis = nowMillis.getAsLong() - startMillis;
// fleetd #494: this release trades a possibly-unsubmitted /clear for progress
// instead of wedging the roll — that trade is deliberate and stays. But it is
// also exactly the case that reported false success in the real incident (the
// whole roll "succeeded" after 438ms of a 20s budget), so raise it to WARN and
// print the MEASURED elapsed time next to the target pane, not just the count.
//
// fleetd #494 follow-up (2nd pass): BOTH numbers in this line must come from
// the loop's own counters, never from the PICKUP_GRACE_POLLS constant.
// `idlePollsAwaitingPickup` and `nudges` each have exactly one write site in
// this loop, on the same branch, so on this branch they cannot differ from
// PICKUP_GRACE_POLLS / PICKUP_GRACE_POLLS - 1 today — no test can prove the
// difference on this line, and printing the counters does not change that.
// What it does buy: one source of truth instead of two, so a later change to
// the loop (an early return, a second increment site, a different exit
// condition) cannot leave this message reporting a number the loop no longer
// produces. The place where `nudges` genuinely varies with the run — and is
// covered by a test that can tell it apart from a constant — is the
// /clear-timeout warn in runRollover, which prints clearResult.nudges().
log.warn("lead-rollover: /clear on {} was never observed as WORKING after {} "
+ "consecutive IDLE/DONE polls ({} of those were nudged) — "
+ "releasing rather than wedging the roll",
target, PICKUP_GRACE_POLLS, PICKUP_GRACE_POLLS - 1);
return true;
+ "releasing rather than wedging the roll (elapsed={}ms)",
target, idlePollsAwaitingPickup, nudges, elapsedMillis);
return new ClearSettleResult(true, elapsedMillis, nudges);
}
try {
agents.submit(target); // nudge a raced Enter (CB-113) so /clear actually submits
} catch (RuntimeException e) {
log.debug("lead-rollover: resubmit to {} failed (will retry next poll): {}",
target, e.getMessage());
} finally {
nudges++; // an attempted nudge, whether or not the submit call itself threw
}
}
// AgentStatus.BLOCKED or UNKNOWN (or an unreadable status, above): neither a pickup
// signal nor a boundary — keep polling without nudging or releasing.
settleSleeper.run();
}
return false;
return new ClearSettleResult(false, nowMillis.getAsLong() - startMillis, nudges);
}
/**
* The measured outcome of {@link #waitForClearPickupAndSettle} — fleetd #494. Carries the
* MEASURED elapsed time (from the injected {@link #nowMillis} clock) and nudge count alongside
* the settle/timeout decision, so callers can log them instead of the configured budget, which
* is not how long the wait actually ran.
*/
private record ClearSettleResult(boolean settled, long elapsedMillis, int nudges) {}
}
@@ -33,9 +33,10 @@ public final class ConnectionIdentity {
/**
* The caller resolved from the connection: its worker {@code terminal} (or {@code null} for the
* primary / an off-host client) and its {@code pid} (or {@code -1} if not resolvable).
* primary / an off-host client), its {@code pid} (or {@code -1} if not resolvable), and whether
* the pane scan behind {@code terminal} ran to completion ({@link #scanComplete}).
*/
public record Caller(String terminal, long pid) {
public record Caller(String terminal, long pid, boolean scanComplete) {
/**
* Whether the OS peer-PID lookup actually succeeded — {@code false} means {@code pid} is
@@ -51,6 +52,10 @@ public final class ConnectionIdentity {
* {@link ConnectionIdentity#isLoopback} is centralised rather than left for each caller to
* reimplement: a raw {@code pid > 0} check duplicated at every call site is precisely the
* "one rule, two copies" shape that let #305 drift.
*
* <p>This method is deliberately NOT widened for fleetd #505's failure (a herdr error
* during the pane scan, not a failed lsof lookup) — it still tests only the sentinel it is
* named for. #505 is a different axis, carried separately in {@link #scanComplete}.
*/
public boolean resolved() {
return pid > 0;
@@ -60,10 +65,11 @@ public final class ConnectionIdentity {
/** Resolve the caller's terminal and PID from one peer-PID lookup. */
public Caller resolve(String remoteAddr, int remotePort) {
if (!isLoopback(remoteAddr)) {
return new Caller(null, -1); // only same-host callers can be workers
return new Caller(null, -1, true); // only same-host callers can be workers
}
long pid = pids.pidForLocalPort(remotePort);
return new Caller(panes.terminalForPid(pid), pid);
PaneLocator.Lookup lookup = panes.terminalForPid(pid);
return new Caller(lookup.terminal(), pid, lookup.complete());
}
/**
@@ -0,0 +1,212 @@
package dev.ltms.fleet;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.read.ListAppender;
import com.fasterxml.jackson.databind.JsonNode;
import dev.ltms.fleet.herdr.HerdrClient;
import dev.ltms.fleet.herdr.HerdrException;
import org.junit.jupiter.api.Test;
import org.slf4j.LoggerFactory;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.function.LongSupplier;
import static org.junit.jupiter.api.Assertions.assertEquals;
import static org.junit.jupiter.api.Assertions.assertFalse;
import static org.junit.jupiter.api.Assertions.assertTrue;
import static org.junit.jupiter.api.Assertions.fail;
/**
* fleetd #498: {@code Fleetd.awaitHerdr} used to return a bare {@code boolean}, collapsing "the
* configured wait budget genuinely ran out" and "the waiting thread was interrupted, possibly
* milliseconds in" onto the same {@code false} — and the caller's log line printed only the
* configured budget, never how long the wait actually ran. This class covers both halves of the
* fix:
* <ul>
* <li>the seam — {@link Fleetd#awaitHerdr} itself, driven with an injected clock and a stub
* {@link HerdrClient}, one test per {@link Fleetd.HerdrWaitResult};</li>
* <li>the call site — {@link Fleetd#logHerdrWaitOutcomeAndShouldReap}, the exact decision {@code
* main} calls (extracted here because {@code main} itself boots the whole daemon and cannot
* be driven from a unit test), pinning the three distinct log messages it emits.</li>
* </ul>
* Every expected message below is a plain literal, not built from {@code HERDR_WAIT_SECONDS} or
* any other production constant — a test that derives its expectation the way the code does
* cannot see a change to either (fleetd #496's identical trap).
*/
class FleetdAwaitHerdrTest {
// ---- the seam: Fleetd.awaitHerdr ----------------------------------------------------------
@Test
void answeredReturnsImmediatelyWithZeroElapsedAndNeverPolls() {
HerdrStub herdr = new HerdrStub(0); // succeeds on the very first call
LongSupplier clock = fixedClock(1_000L);
AtomicBoolean polled = new AtomicBoolean(false);
Runnable poller = () -> polled.set(true);
Fleetd.HerdrAwaitOutcome outcome = Fleetd.awaitHerdr(herdr, clock, poller);
assertEquals(Fleetd.HerdrWaitResult.ANSWERED, outcome.result());
assertEquals(0L, outcome.elapsedNanos(), "a fixed clock must measure zero elapsed time");
assertFalse(polled.get(), "herdr answering on the first try must never poll");
}
@Test
void deadlinePassedIsMeasuredNotAssumed() {
HerdrStub herdr = new HerdrStub(-1); // never succeeds
// call order inside awaitHerdr: start, then per failed attempt: deadline-check, elapsed-calc
ScriptedClock clock = new ScriptedClock(0L, 30_500_000_000L, 30_500_000_000L);
Runnable poller = () -> fail("the deadline was already exceeded on the first attempt — must not poll");
Fleetd.HerdrAwaitOutcome outcome = Fleetd.awaitHerdr(herdr, clock, poller);
assertEquals(Fleetd.HerdrWaitResult.DEADLINE_PASSED, outcome.result());
assertEquals(30_500_000_000L, outcome.elapsedNanos(),
"elapsed must be the MEASURED clock delta, not the configured budget");
}
@Test
void interruptedIsDistinctFromDeadlinePassedAndPreservesTheInterruptFlag() {
HerdrStub herdr = new HerdrStub(-1); // never succeeds
// start=0, deadline-check returns 500ms (well under the 30s budget) -> not deadline-passed,
// then the poller interrupts, and the elapsed-calc call returns 750ms.
ScriptedClock clock = new ScriptedClock(0L, 500_000_000L, 750_000_000L);
Runnable poller = () -> Thread.currentThread().interrupt();
try {
Fleetd.HerdrAwaitOutcome outcome = Fleetd.awaitHerdr(herdr, clock, poller);
assertEquals(Fleetd.HerdrWaitResult.INTERRUPTED, outcome.result());
assertEquals(750_000_000L, outcome.elapsedNanos(),
"elapsed must be measured even when the wait ends via interruption, not the deadline");
assertTrue(Thread.currentThread().isInterrupted(),
"the interrupt flag the old code re-set must still be set on return");
} finally {
Thread.interrupted(); // clear it so it cannot leak into another test on this thread
}
}
// ---- the call site: Fleetd.logHerdrWaitOutcomeAndShouldReap -------------------------------
@Test
void answeredLogsNothingAndSaysReap() {
ListAppender<ILoggingEvent> events = attach();
try {
boolean shouldReap = Fleetd.logHerdrWaitOutcomeAndShouldReap(
new Fleetd.HerdrAwaitOutcome(Fleetd.HerdrWaitResult.ANSWERED, 0L));
assertTrue(shouldReap, "only ANSWERED should tell main to reap orphan workers");
assertEquals(0, events.list.size(), "the answered path logs nothing itself");
} finally {
detach(events);
}
}
@Test
void deadlinePassedLogsConfiguredAndMeasuredElapsedTogether() {
ListAppender<ILoggingEvent> events = attach();
try {
boolean shouldReap = Fleetd.logHerdrWaitOutcomeAndShouldReap(
new Fleetd.HerdrAwaitOutcome(Fleetd.HerdrWaitResult.DEADLINE_PASSED, 30_500_000_000L));
assertFalse(shouldReap, "a deadline-passed wait must not tell main to reap");
assertEquals(1, events.list.size());
ILoggingEvent event = events.list.getFirst();
assertEquals(Level.WARN, event.getLevel());
assertEquals("herdr did not answer within the configured wait (configured=30s "
+ "elapsed=30500ms) — starting anyway; /healthz will report degraded until it "
+ "comes up. Orphaned worker panes (if any) were NOT reaped.",
event.getFormattedMessage());
} finally {
detach(events);
}
}
@Test
void interruptedLogsItsOwnMessageAndNeverClaimsTheBudgetElapsed() {
ListAppender<ILoggingEvent> events = attach();
try {
// 3ms: the ticket's own example of "a few milliseconds in", not the 30s budget.
boolean shouldReap = Fleetd.logHerdrWaitOutcomeAndShouldReap(
new Fleetd.HerdrAwaitOutcome(Fleetd.HerdrWaitResult.INTERRUPTED, 3_000_000L));
assertFalse(shouldReap, "an interrupted wait must not tell main to reap");
assertEquals(1, events.list.size());
ILoggingEvent event = events.list.getFirst();
assertEquals(Level.WARN, event.getLevel());
String message = event.getFormattedMessage();
assertEquals("herdr wait was interrupted before the configured wait ran out "
+ "(configured=30s elapsed=3ms) — starting anyway; /healthz will report "
+ "degraded until it comes up. Orphaned worker panes (if any) were NOT reaped.",
message);
assertFalse(message.contains("did not answer"),
"an interrupted wait must not be reported as if herdr failed to answer within the budget");
} finally {
detach(events);
}
}
// ---- fixtures --------------------------------------------------------------------------
/** Always returns the same value, i.e. a clock that measures zero elapsed time. */
private static LongSupplier fixedClock(long value) {
return () -> value;
}
/** Returns each value in order, then repeats the last one for any call beyond the list. */
private static final class ScriptedClock implements LongSupplier {
private final long[] values;
private int index;
ScriptedClock(long... values) {
this.values = values;
}
@Override
public long getAsLong() {
long v = values[Math.min(index, values.length - 1)];
if (index < values.length - 1) {
index++;
}
return v;
}
}
/** Fails {@code failuresBeforeSuccess} times, then succeeds forever; {@code -1} never succeeds. */
private static final class HerdrStub implements HerdrClient {
private final int failuresBeforeSuccess;
private int calls;
HerdrStub(int failuresBeforeSuccess) {
this.failuresBeforeSuccess = failuresBeforeSuccess;
}
@Override
public JsonNode call(String method, Object params) throws HerdrException {
calls++;
if (failuresBeforeSuccess < 0 || calls <= failuresBeforeSuccess) {
throw new HerdrException("herdr not up yet");
}
return null;
}
@Override
public void close() {
}
}
private static ListAppender<ILoggingEvent> attach() {
Logger logger = (Logger) LoggerFactory.getLogger(Fleetd.class);
logger.setLevel(Level.DEBUG);
ListAppender<ILoggingEvent> appender = new ListAppender<>();
appender.start();
logger.addAppender(appender);
return appender;
}
private static void detach(ListAppender<ILoggingEvent> appender) {
((Logger) LoggerFactory.getLogger(Fleetd.class)).detachAppender(appender);
}
}
@@ -186,6 +186,43 @@ class CallerResolverTest {
assertEquals(Role.PRIMARY, r.resolve("127.0.0.1", 99, "BEARER s3cret").role());
}
// ── fleetd #505: a herdr error DURING THE SCAN must not be conflated with "not a worker" ──────
// #317 (above) covers a failed lsof lookup. This is the other input to the same decision: the
// lsof lookup succeeds (a real pid), but PaneLocator's own pane scan hits a herdr error on the
// pane that owns that pid — so c.resolved() is true and c.terminal() is null, exactly like a
// real primary. c.scanComplete() is what tells them apart.
/**
* The discriminating case named in the ticket: the error must land on the pane that DOES own
* the caller's pid, or the test proves nothing (any other pane's failure is invisible to the
* scan's outcome, since a match found elsewhere is definitive regardless).
*/
@Test
void aHerdrErrorOnTheOwningPaneDuringTheScanIsRefusedNotPromotedToPrimary() {
FakeHerdr failing = new FakeHerdr().processInfoFailsForPane("w2:p7", "transient");
ConnectionIdentity incomplete = new ConnectionIdentity(new PaneLocator(failing), _ -> FakeHerdr.WORKER_PID);
Principal p = new CallerResolver(incomplete).resolve("127.0.0.1", 55555, null);
assertEquals(Role.ANONYMOUS, p.role(),
"an incomplete pane scan must never be read as a clean negative and promoted to primary");
}
/**
* The companion invariant: a herdr error on a DIFFERENT, non-owning pane must not turn every
* mid-scan teardown into a refusal — the real match is still found and resolves as a worker.
*/
@Test
void aHerdrErrorOnANonOwningPaneStillResolvesTheRealWorker() {
FakeHerdr vanishedElsewhere = new FakeHerdr().processInfoFailsForPane("w2:p9", "pane_not_found");
ConnectionIdentity id = new ConnectionIdentity(new PaneLocator(vanishedElsewhere), _ -> FakeHerdr.WORKER_PID);
Principal p = new CallerResolver(id).resolve("127.0.0.1", 55555, null);
assertEquals(Role.WORKER, p.role());
assertEquals("term_a", p.terminal());
}
@Test
void aNonLoopbackCallerIsNeverThePrimaryUnderLoopbackTrust() {
// Defence in depth: startup already refuses this pairing (validateAuthExposure), but if a
@@ -44,6 +44,7 @@ public final class FakeHerdr implements HerdrClient {
private int workerTabPaneCount = 1;
private String paneCloseErrorCode = null;
private final Map<String, String> paneCloseErrorCodeFor = new ConcurrentHashMap<>();
private final Map<String, String> processInfoErrorCodeFor = new ConcurrentHashMap<>();
private String tabCloseErrorCode = null;
private final Map<String, String> tabCloseErrorCodeFor = new ConcurrentHashMap<>();
private String agentSendErrorCode = null;
@@ -144,6 +145,18 @@ public final class FakeHerdr implements HerdrClient {
return this;
}
/**
* Make {@code pane.process_info} fail with this herdr error code, but only for the given
* {@code pane_id} — every other pane's {@code pane.process_info} still succeeds. Models a
* transient herdr failure partway through a {@link PaneLocator} pid→pane scan (fleetd #505):
* the scan must be able to tell "this pane does not own the pid" apart from "the scan could
* not check this pane at all", instead of collapsing both into one {@code false}.
*/
public FakeHerdr processInfoFailsForPane(String paneId, String code) {
this.processInfoErrorCodeFor.put(paneId, code);
return this;
}
/** Set the {@code agent_status} that {@code agent.get} reports (drives the injector). */
public FakeHerdr agentStatus(String status) {
this.agentStatus = status;
@@ -407,6 +420,13 @@ public final class FakeHerdr implements HerdrClient {
{"pane_id":"w2:p9","terminal_id":"term_shell","workspace_id":"w2","tab_id":"w2:t8"}]}""");
case "pane.process_info" -> {
Object paneId = params instanceof java.util.Map<?, ?> m ? m.get("pane_id") : null;
String failCode = paneId == null ? null
: processInfoErrorCodeFor.get(String.valueOf(paneId));
if (failCode != null) {
throw new HerdrException(
"herdr error [" + failCode + "]: pane.process_info failed",
failCode, null);
}
yield "w2:p7".equals(paneId)
? mapper.readTree(("""
{"type":"pane_process_info","process_info":{"pane_id":"w2:p7","shell_pid":%d,
@@ -37,7 +37,7 @@ class PaneLocatorContractTest {
.path("pane").path("terminal_id").asText(null);
assertNotNull(terminalId, "seed pane should carry a terminal_id");
assertEquals(terminalId, new PaneLocator(herdr).terminalForPid(shellPid),
assertEquals(terminalId, new PaneLocator(herdr).terminalForPid(shellPid).terminal(),
"a real PID must resolve back to its own pane's terminal_id");
} finally {
spaces.closeTab(tab.tab().tabId());
@@ -15,18 +15,20 @@ class PaneLocatorTest {
@Test
void resolvesTerminalForAForegroundPid() {
assertEquals("term_a", loc.terminalForPid(FakeHerdr.WORKER_PID));
assertEquals("term_a", loc.terminalForPid(FakeHerdr.WORKER_PID).terminal());
}
@Test
void nullForAPidInNoPane() {
assertNull(loc.terminalForPid(999_999));
PaneLocator.Lookup outcome = loc.terminalForPid(999_999);
assertNull(outcome.terminal());
assertTrue(outcome.complete(), "a full, error-free scan that finds no match is complete");
}
@Test
void nullForNonPositivePid() {
assertNull(loc.terminalForPid(0));
assertNull(loc.terminalForPid(-1));
assertNull(loc.terminalForPid(0).terminal());
assertNull(loc.terminalForPid(-1).terminal());
}
// --- two-daemon fallback (CB-185) -----------------------------------------
@@ -38,7 +40,7 @@ class PaneLocatorTest {
HerdrClient lead = new FakeHerdr().withNoPanes();
HerdrClient member = new FakeHerdr();
PaneLocator two = new PaneLocator(lead, member);
assertEquals("term_a", two.terminalForPid(FakeHerdr.WORKER_PID));
assertEquals("term_a", two.terminalForPid(FakeHerdr.WORKER_PID).terminal());
}
@Test
@@ -48,13 +50,13 @@ class PaneLocatorTest {
HerdrClient lead = new FakeHerdr();
HerdrClient member = new FakeHerdr().withNoPanes();
PaneLocator two = new PaneLocator(lead, member);
assertEquals("term_a", two.terminalForPid(FakeHerdr.WORKER_PID));
assertEquals("term_a", two.terminalForPid(FakeHerdr.WORKER_PID).terminal());
}
@Test
void nullWhenNeitherClientHasTheMatch() {
PaneLocator two = new PaneLocator(new FakeHerdr().withNoPanes(), new FakeHerdr().withNoPanes());
assertNull(two.terminalForPid(FakeHerdr.WORKER_PID));
assertNull(two.terminalForPid(FakeHerdr.WORKER_PID).terminal());
}
@Test
@@ -63,7 +65,7 @@ class PaneLocatorTest {
// must behave exactly like the one-arg constructor, including making only one herdr call.
FakeHerdr shared = new FakeHerdr();
PaneLocator two = new PaneLocator(shared, shared);
assertEquals("term_a", two.terminalForPid(FakeHerdr.WORKER_PID));
assertEquals("term_a", two.terminalForPid(FakeHerdr.WORKER_PID).terminal());
long paneListCalls = shared.calls.stream().filter(c -> c.method().equals("pane.list")).count();
assertEquals(1, paneListCalls, "same-object lead/member must scan exactly once, not twice");
}
@@ -75,7 +77,7 @@ class PaneLocatorTest {
// Regression: a pid with no parent chain at all — no ancestry walk is needed to match it.
OnePaneHerdr pane = new OnePaneHerdr("term_x", "pX", 5000, 6000);
PaneLocator loc = new PaneLocator(pane, new FakeParentResolver());
assertEquals("term_x", loc.terminalForPid(5000));
assertEquals("term_x", loc.terminalForPid(5000).terminal());
}
@Test
@@ -83,7 +85,7 @@ class PaneLocatorTest {
// Regression: same as above, but matching via the foreground-processes list.
OnePaneHerdr pane = new OnePaneHerdr("term_x", "pX", 5000, 6000);
PaneLocator loc = new PaneLocator(pane, new FakeParentResolver());
assertEquals("term_x", loc.terminalForPid(6000));
assertEquals("term_x", loc.terminalForPid(6000).terminal());
}
@Test
@@ -97,7 +99,7 @@ class PaneLocatorTest {
.parent(7002, 7001) // grandchild -> child
.parent(7001, 5000); // child -> shell (the pane's shell_pid)
PaneLocator loc = new PaneLocator(pane, parents);
assertEquals("term_x", loc.terminalForPid(7002));
assertEquals("term_x", loc.terminalForPid(7002).terminal());
}
@Test
@@ -110,7 +112,7 @@ class PaneLocatorTest {
.parent(9002, 9001)
.parent(9001, 9000); // chain never reaches 5000 or 6000
PaneLocator loc = new PaneLocator(pane, parents);
assertNull(loc.terminalForPid(9002));
assertNull(loc.terminalForPid(9002).terminal());
}
@Test
@@ -122,7 +124,7 @@ class PaneLocatorTest {
.parent(100, 101)
.parent(101, 100); // cycle, never reaches the pane's pids
PaneLocator loc = new PaneLocator(pane, parents);
assertNull(loc.terminalForPid(100));
assertNull(loc.terminalForPid(100).terminal());
}
@Test
@@ -141,11 +143,43 @@ class PaneLocatorTest {
};
HerdrClient noPanes = new FakeHerdr().withNoPanes();
PaneLocator two = new PaneLocator(noPanes, pane, counting);
assertEquals("term_x", two.terminalForPid(7002));
assertEquals("term_x", two.terminalForPid(7002).terminal());
assertEquals(3, calls.get(), "ancestry must be walked once (3 lookups: 7002, 7001, 5000), "
+ "not re-walked per herdr client");
}
// --- fleetd #505: a herdr error during the scan must not read as a clean negative ---------
@Test
void anErrorOnThePaneThatOwnsThePidMakesTheScanIncompleteNotAClearNegative() {
// The discriminating case: pane.process_info fails for exactly the pane that DOES own the
// caller's pid ("w2:p7", term_a). Before the fix, that failure was swallowed into a plain
// "does not own it" and the scan finished with a clean-looking null — indistinguishable
// from a real primary. It must now report incomplete, not a definite null.
FakeHerdr herdr = new FakeHerdr().processInfoFailsForPane("w2:p7", "transient");
PaneLocator loc = new PaneLocator(herdr);
PaneLocator.Lookup outcome = loc.terminalForPid(FakeHerdr.WORKER_PID);
assertNull(outcome.terminal(), "the failing pane's ownership could not be confirmed");
assertFalse(outcome.complete(),
"a scan that could not check the owning pane must not report as complete");
}
@Test
void aVanishedPaneThatIsNotTheMatchLeavesAnOtherwiseSuccessfulScanComplete() {
// The companion invariant: a DIFFERENT pane (not the caller's own) failing mid-scan must
// not turn every mid-scan teardown into a refusal — the real match is still found, and the
// scan is still reported complete.
FakeHerdr herdr = new FakeHerdr().processInfoFailsForPane("w2:p9", "pane_not_found");
PaneLocator loc = new PaneLocator(herdr);
PaneLocator.Lookup outcome = loc.terminalForPid(FakeHerdr.WORKER_PID);
assertEquals("term_a", outcome.terminal());
assertTrue(outcome.complete(), "a positive match elsewhere in the scan is definitive");
}
/** 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();
@@ -19,6 +19,8 @@ import java.util.Set;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.ExecutionException;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.function.LongSupplier;
import static org.junit.jupiter.api.Assertions.*;
@@ -521,6 +523,97 @@ class InjectorTest {
}
}
@Test
void readinessGraceExpiryLogsTheMeasuredPollCountNextToTheConfiguredBudget() {
// fleetd #501, defect 1: READINESS_GRACE_POLLS (240) used to be printed twice — once as
// "after {} polls" and once inside the parenthesised budget — even though the loop's own
// counter (Target.notReadySincePoll) was in scope at the same call site. On THIS branch the
// counter has just reached the threshold, so it equals the constant by construction and this
// test cannot tell the two apart — it only pins that the message still carries both a poll
// count and a labelled configured budget, using literal numbers (240, 60), never
// READINESS_GRACE_POLLS or POLL_INTERVAL_MILLIS, so the assertion can't silently track a
// constant change instead of catching a real regression.
LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
ch.qos.logback.classic.Logger injectorLog =
(ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Injector.class);
ListAppender<ILoggingEvent> appender = new ListAppender<>();
appender.setContext(ctx);
appender.start();
injectorLog.addAppender(appender);
injectorLog.setLevel(Level.WARN);
try {
Injector inj = new Injector(new AgentControl(herdr), TurnListener.NOOP, _ -> false, _ -> {
});
inj.enqueue(T, "task", TestTurnTokens.inert(T));
for (int i = 0; i < READINESS_SAMPLES; i++) inj.onStatus(T, AgentStatus.IDLE);
String warn = appender.list.stream()
.filter(e -> e.getLevel().equals(Level.WARN))
.map(ILoggingEvent::getFormattedMessage)
.findFirst()
.orElse("no grace-expiry WARN logged");
assertTrue(warn.contains("after 240 polls"),
"must print the measured poll count as a plain number: " + warn);
assertTrue(warn.contains("configured=240 polls/60s"),
"must print the configured budget, clearly labelled: " + warn);
} finally {
injectorLog.detachAppender(appender);
}
}
@Test
void readinessGraceExpiryLogsTheMeasuredElapsedTimeNotArithmeticOnConstants() {
// fleetd #501, defect 2: the old line computed "({}s)" as READINESS_GRACE_POLLS *
// POLL_INTERVAL_MILLIS / 1000 — arithmetic on two constants, never a measurement, and wrong
// in the direction that says everything ran on schedule. This stub clock returns two FIXED
// values (1_000ms at the first non-ready sample, 318_412ms at the poll that trips the grace)
// whose difference — 317_412ms — does NOT equal 240 * POLL_INTERVAL_MILLIS (=60_000ms).
// Asserting on that literal, non-derived number is what makes this test able to fail if the
// production code goes back to printing the constant-arithmetic value instead of the
// injected clock's measurement.
long[] readings = {1_000L, 318_412L};
AtomicInteger call = new AtomicInteger(0);
LongSupplier stubClock = () -> {
int i = call.getAndIncrement();
if (i >= readings.length) {
throw new AssertionError("nowMillis read more times than this fixture expects (" + i
+ "); the readiness-not-ready branch should read the clock exactly twice — "
+ "once to stamp the first non-ready sample, once at grace expiry");
}
return readings[i];
};
LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
ch.qos.logback.classic.Logger injectorLog =
(ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Injector.class);
ListAppender<ILoggingEvent> appender = new ListAppender<>();
appender.setContext(ctx);
appender.start();
injectorLog.addAppender(appender);
injectorLog.setLevel(Level.WARN);
try {
Injector inj = new Injector(new AgentControl(herdr), TurnListener.NOOP, _ -> false, _ -> {
}, stubClock);
inj.enqueue(T, "task", TestTurnTokens.inert(T));
for (int i = 0; i < READINESS_SAMPLES; i++) inj.onStatus(T, AgentStatus.IDLE);
String warn = appender.list.stream()
.filter(e -> e.getLevel().equals(Level.WARN))
.map(ILoggingEvent::getFormattedMessage)
.findFirst()
.orElse("no grace-expiry WARN logged");
assertTrue(warn.contains("elapsed=317412ms"), "must print the MEASURED elapsed time from "
+ "the injected clock (318412 - 1000 = 317412), not an arithmetic value: " + warn);
assertFalse(warn.contains("elapsed=60000ms"), "must not print "
+ "READINESS_GRACE_POLLS * POLL_INTERVAL_MILLIS (240 * 250 = 60000ms) as if it "
+ "were the measured elapsed time: " + warn);
} finally {
injectorLog.detachAppender(appender);
}
}
@Test
void aWorkerThatBecomesReadyWithinTheGraceIsDeliveredNormally() {
// The readiness grace must not fail a worker that is merely slow to boot: once it becomes
@@ -1,5 +1,9 @@
package dev.ltms.fleet.lead;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.read.ListAppender;
import com.fasterxml.jackson.databind.JsonNode;
import dev.ltms.fleet.config.FleetConfig;
import dev.ltms.fleet.herdr.AgentControl;
@@ -9,6 +13,7 @@ import dev.ltms.fleet.herdr.HerdrException;
import org.junit.jupiter.api.DisplayName;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.io.TempDir;
import org.slf4j.LoggerFactory;
import java.io.IOException;
import java.nio.file.Files;
@@ -854,4 +859,207 @@ class LeadRolloverTest {
assertFalse(bootstrapSent.contains("\"handover.md\""),
"must not name the raw relative configured value in the text actually sent");
}
// ---- fleetd #494: the log lines must print MEASURED values, never the configured budget --
private static ListAppender<ILoggingEvent> attachLog() {
Logger logger = (Logger) LoggerFactory.getLogger(LeadRollover.class);
logger.setLevel(Level.DEBUG);
ListAppender<ILoggingEvent> appender = new ListAppender<>();
appender.start();
logger.addAppender(appender);
return appender;
}
private static void detachLog(ListAppender<ILoggingEvent> appender) {
((Logger) LoggerFactory.getLogger(LeadRollover.class)).detachAppender(appender);
}
private static ILoggingEvent lastEventContaining(ListAppender<ILoggingEvent> events, String substring) {
return events.list.stream()
.filter(e -> e.getFormattedMessage().contains(substring))
.reduce((_, b) -> b)
.orElseThrow(() -> new AssertionError("no log event contained \"" + substring
+ "\"; got: " + events.list.stream().map(ILoggingEvent::getFormattedMessage).toList()));
}
@Test
@DisplayName("[fleetd #494] the /clear-timeout warn line prints the MEASURED elapsed time and "
+ "nudge count next to the configured budget, never the configured value alone")
void clearTimeoutLogPrintsMeasuredElapsedAndNudgesNotJustConfigured() throws IOException {
// Idle until /clear is sent, then permanently WORKING (a genuinely stuck /clear that never
// reaches a completion boundary) — isolates the SECOND wait exactly like
// clearThatNeverSettlesAfterwardsNeverSendsBootstrapText, but with a clock that ADVANCES on
// every read so the measured elapsed time is a deterministic, non-zero value distinct from
// the configured budget — pinning fleetd #494's fix, not just its absence of a hang.
FakeHerdr fake = new FakeHerdr();
HerdrClient flipsAfterClear = new HerdrClient() {
@Override
public JsonNode call(String method, Object params) throws HerdrException {
JsonNode result = fake.call(method, params);
if ("agent.prompt".equals(method) && String.valueOf(params).contains("/clear")) {
fake.agentStatus("working");
}
return result;
}
@Override
public void close() {
fake.close();
}
};
Path handover = writeHandover("handover contents");
FleetConfig.LeadRollover config =
new FleetConfig.LeadRollover(handover.toString(), true, 3600, 20, 1 /*clearSettleSeconds*/, "boot text");
AtomicLong clock = new AtomicLong(1_000);
LeadRollover rollover = newRollover(flipsAfterClear, config, () -> clock.addAndGet(500));
ListAppender<ILoggingEvent> events = attachLog();
try {
LeadRollover.PendingRollover pending = rollover.open(LEAD, "context is full");
LeadRollover.RollDecision decision = rollover.confirm(LEAD, pending.token(), true);
assertTrue(decision.accepted(), "every synchronous gate passes; the refusal is logged "
+ "only, deep inside the deferred continuation");
ILoggingEvent event = lastEventContaining(events, "NOT sending bootstrapText");
assertEquals(Level.WARN, event.getLevel());
String message = event.getFormattedMessage();
assertTrue(message.contains("configured=1s"), "must label the configured budget: " + message);
assertTrue(message.contains("elapsed=1500ms"), "must print the MEASURED elapsed time — "
+ "with this fixture's advancing clock, the wait actually ran 1500ms against a "
+ "1s(=1000ms) configured budget: " + message);
assertTrue(message.contains("nudges=0"), "must print the measured nudge count (0 here — "
+ "the pane was WORKING throughout, never IDLE/DONE, so no nudge was ever sent): "
+ message);
assertFalse(message.contains("within 1s"), "must not present the configured budget as if "
+ "it were the measured wait duration: " + message);
} finally {
detachLog(events);
}
}
@Test
@DisplayName("[fleetd #494] the /clear pickup-grace release line is WARN (was INFO) and prints "
+ "the measured elapsed time next to the target pane")
void clearGraceReleaseLogIsWarnWithMeasuredElapsed() throws IOException {
// Default idle throughout — no WORKING sample is ever observed, so the pickup-grace wait
// exhausts PICKUP_GRACE_POLLS and releases rather than wedging (see
// clearPickupIsNudgedBeforeBootstrapTextWhenPaneStaysIdle for the un-logged half of this
// scenario). A self-advancing clock makes the measured elapsed time deterministic and
// provably distinct from a bare poll/nudge count.
FakeHerdr herdr = new FakeHerdr();
Path handover = writeHandover("handover contents");
FleetConfig.LeadRollover config = cfg(handover.toString()); // turnSettleSeconds=clearSettleSeconds=20
AtomicLong clock = new AtomicLong(1_000);
LeadRollover rollover = newRollover(herdr, config, () -> clock.addAndGet(500));
ListAppender<ILoggingEvent> events = attachLog();
try {
LeadRollover.PendingRollover pending = rollover.open(LEAD, "context is full");
LeadRollover.RollDecision decision = rollover.confirm(LEAD, pending.token(), true);
assertTrue(decision.accepted(), "expected approval; got: " + decision.reason()
+ " / " + decision.detail());
ILoggingEvent event = lastEventContaining(events, "releasing rather than wedging the roll");
assertEquals(Level.WARN, event.getLevel(), "the grace-limit release must be WARN, not "
+ "INFO — it is exactly the case that reported false success in the real incident "
+ "this fix comes from (a roll that 'succeeded' after 438ms of a 20s budget)");
String message = event.getFormattedMessage();
assertTrue(message.contains(LEAD), "must name the target pane: " + message);
assertTrue(message.contains("elapsed=4500ms"), "must print the MEASURED elapsed time — "
+ "with this fixture's advancing clock, the wait ran 4500ms before releasing: "
+ message);
// fleetd #494 follow-up (2nd pass): both numbers here are DELIBERATE plain literals,
// not derived from LeadRollover.PICKUP_GRACE_POLLS. A version of this assertion that
// reads "(" + (LeadRollover.PICKUP_GRACE_POLLS - 1) + " of those were nudged)" builds
// its expectation the same way the production code used to build the log line, so it
// cannot tell a fixed constant apart from the measured counter — proved by reverting
// the production fix and re-running: that mutant stayed green under the old assertion.
// If PICKUP_GRACE_POLLS ever changes, THIS TEST MUST FAIL and a human must look at the
// new message and update the literals below, not just re-derive them.
assertTrue(message.contains("after 8 consecutive IDLE/DONE polls (7 of those were nudged)"),
"must print the measured poll count and nudge count as plain numbers, not the "
+ "PICKUP_GRACE_POLLS constant standing in for either: " + message);
} finally {
detachLog(events);
}
}
@Test
@DisplayName("[fleetd #494] the success line prints the measured elapsed time for the whole roll")
void successLogPrintsMeasuredElapsedForTheWholeRoll() throws IOException {
// Same fixture as clearGraceReleaseLogIsWarnWithMeasuredElapsed: default idle throughout, so
// the grace release fires and the roll still goes on to send bootstrapText and log success.
// This is deliberately the SAME shape as the real incident (a roll that "succeeds" quickly)
// — the missing signal was the elapsed time on this exact line.
FakeHerdr herdr = new FakeHerdr();
Path handover = writeHandover("handover contents");
FleetConfig.LeadRollover config = cfg(handover.toString());
AtomicLong clock = new AtomicLong(1_000);
LeadRollover rollover = newRollover(herdr, config, () -> clock.addAndGet(500));
ListAppender<ILoggingEvent> events = attachLog();
try {
LeadRollover.PendingRollover pending = rollover.open(LEAD, "context is full");
LeadRollover.RollDecision decision = rollover.confirm(LEAD, pending.token(), true);
assertTrue(decision.accepted(), "expected approval; got: " + decision.reason()
+ " / " + decision.detail());
ILoggingEvent event = lastEventContaining(events, "lead-rollover: rolled");
assertEquals(Level.INFO, event.getLevel());
String message = event.getFormattedMessage();
// fleetd #494 follow-up: waitUntilAtTurnBoundary now also reads the injected clock one
// extra time (to compute ITS OWN measured elapsed on the success path), so the shared
// fixture clock advances by one more 500ms tick before the roll finishes than it did
// before that follow-up — 7000ms, not 6500ms.
assertTrue(message.contains("elapsedMs=7000"), "must print the MEASURED elapsed time for "
+ "the whole roll — with this fixture's advancing clock, the full roll (turn-settle "
+ "wait + /clear wait + bootstrapText) took 7000ms: " + message);
} finally {
detachLog(events);
}
}
@Test
@DisplayName("[fleetd #494 follow-up] the turn-settle timeout warn line prints the MEASURED "
+ "elapsed time next to the configured budget, never the configured value alone")
void turnTimeoutLogPrintsMeasuredElapsedNotJustConfigured() throws IOException {
// The brief that named the four items this ticket fixed left this exact sibling line out —
// "did not reach a turn boundary (IDLE or DONE) within {}s after confirm()" — even though it
// has the identical defect shape one method below. Same fixture shape as
// clearTimeoutLogPrintsMeasuredElapsedAndNudgesNotJustConfigured, but for the FIRST wait: the
// calling lead's own pane never goes idle, so waitUntilAtTurnBoundary times out.
FakeHerdr herdr = new FakeHerdr();
herdr.agentStatus("working"); // the calling lead's own pane — never goes idle in this test
Path handover = writeHandover("handover contents");
FleetConfig.LeadRollover config =
new FleetConfig.LeadRollover(handover.toString(), true, 3600, 1 /*turnSettleSeconds*/, 20, "text");
AtomicLong clock = new AtomicLong(1_000);
LeadRollover rollover = newRollover(herdr, config, () -> clock.addAndGet(500));
ListAppender<ILoggingEvent> events = attachLog();
try {
LeadRollover.PendingRollover pending = rollover.open(LEAD, "context is full");
LeadRollover.RollDecision decision = rollover.confirm(LEAD, pending.token(), true);
assertTrue(decision.accepted(), "every synchronous gate should pass; the refusal happens "
+ "only inside the deferred continuation, which this test's synchronous runner "
+ "has already run to completion by the time confirm() returns");
ILoggingEvent event = lastEventContaining(events, "refusing to send /clear at all");
assertEquals(Level.WARN, event.getLevel());
String message = event.getFormattedMessage();
assertTrue(message.contains("configured=1s"), "must label the configured budget: " + message);
assertTrue(message.contains("elapsed=1500ms"), "must print the MEASURED elapsed time — "
+ "with this fixture's advancing clock, the wait actually ran 1500ms against a "
+ "1s(=1000ms) configured budget: " + message);
assertFalse(message.contains("within 1s"), "must not present the configured budget as if "
+ "it were the measured wait duration: " + message);
} finally {
detachLog(events);
}
}
}
@@ -57,6 +57,23 @@ class ConnectionIdentityTest {
// must read as "resolved" — the distinction #317 turns on.
ConnectionIdentity.Caller c = with(_ -> 999_999).resolve("127.0.0.1", 55555);
assertTrue(c.resolved());
assertTrue(c.scanComplete(), "no herdr error happened, so the scan is complete");
}
@Test
void scanIsIncompleteWhenHerdrErrorsOnThePaneThatOwnsThePid() {
// fleetd #505: a transient herdr error on exactly the pane that DOES own the caller's pid
// must be visible as an incomplete scan, distinct from a real primary (resolved(), null
// terminal, complete scan). Both have pid > 0 and a null terminal — scanComplete is the
// only thing that tells them apart.
FakeHerdr failing = new FakeHerdr().processInfoFailsForPane("w2:p7", "transient");
ConnectionIdentity id = new ConnectionIdentity(new PaneLocator(failing), _ -> FakeHerdr.WORKER_PID);
ConnectionIdentity.Caller c = id.resolve("127.0.0.1", 55555);
assertTrue(c.resolved(), "the pid itself resolved fine — this is not #317's failure");
assertNull(c.terminal(), "the owning pane could not be confirmed");
assertFalse(c.scanComplete(), "the scan could not check the pane that owns this pid");
}
@Test
+173 -15
View File
@@ -34,7 +34,11 @@
# three different answers, drives whichever one it finds through its own control plane
# (`launchctl` / `systemctl --user`), and REFUSES outright — never falls back to `kill` — when
# it finds a supervision signal it cannot map to exactly one of the two it knows how to drive.
# A wrong guess here is how two daemons end up running against one herdr session.
# A wrong guess here is how two daemons end up running against one herdr session. Follow-up:
# "not currently loaded" is not the same fact as "unsupervised" — a unit that is installed but
# activating/failed/pending-restart, or a `systemctl` call that could not answer at all (e.g.
# no user-bus access), both now read as a fifth answer, "unclear", and REFUSE the same way
# "ambiguous" does, rather than silently falling through to "none".
# 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.
@@ -71,6 +75,30 @@ LAUNCHD_PLIST="$HOME/Library/LaunchAgents/$LAUNCHD_LABEL.plist"
# "dev.ltms.fleetd" — systemd user units here are not namespaced the way the launchd label is).
SYSTEMD_UNIT='fleetd'
# fleetd #492 follow-up: detect_supervisor packs TWO values (kind, detail) onto the one stdout
# line that survives its $(...) call — see the constraints comment above that function. This is
# the separator between them: the ASCII "unit separator" byte, chosen because it never occurs in
# any of the prose detail strings and needs no escaping in a `case`/glob pattern.
SUPERVISOR_DETAIL_SEP=$'\x1f'
# fleetd #492 follow-up: set by systemd_loaded/systemd_installed when the underlying `systemctl`
# call could not answer cleanly — it exited non-zero AND wrote something to stderr, which is a real
# tool failure (e.g. it cannot reach the user bus over a non-lingering ssh session), never the same
# fact as a clean negative answer ("not active", no stderr). Initialized here, not just inside the
# probes, so detect_supervisor can read them under `set -u` even before either probe has ever run,
# and so a test that stubs a probe with a plain `return 0`/`return 1` body (leaving these untouched)
# reads a deterministic 0 rather than whatever a previous probe call left behind.
SYSTEMD_LOADED_ERRORED=0
SYSTEMD_INSTALLED_ERRORED=0
# fleetd #492 follow-up: SUPERVISOR_UNCLEAR_DETAIL is the specific supervisor/reason that
# require_drivable_supervisor's die() names on an "unclear" answer. Deliberately NOT pre-declared
# here (unlike the two flags above): it is set only by the real call site, right after it unpacks
# detect_supervisor's stdout (see the constraints comment above detect_supervisor). If that call
# site is ever skipped or broken, a bare `set -u` reference to this variable in
# require_drivable_supervisor must fail loudly with "unbound variable" — a pre-declared empty
# default would instead silently print an empty reason, hiding exactly the value this ticket
# exists to surface.
DO_BUILD=1; ASSUME_YES=0; CHECK_ONLY=0
for arg in "$@"; do
case "$arg" in
@@ -100,39 +128,128 @@ launchd_loaded() { launchctl list "$LAUNCHD_LABEL" >/dev/null 2>&1; }
# (this repo is developed on macOS) can substitute each one independently — the same seam
# launchd_installed/launchd_loaded above already use.
#
# fleetd #492 follow-up: both functions used to throw `systemctl`'s stderr straight into
# /dev/null, which meant "systemctl answered no" and "systemctl could not answer at all" (e.g. it
# cannot reach the user bus over a non-lingering ssh session) looked identical — both a plain
# nonzero exit. They now capture stderr separately and set their own *_ERRORED flag ONLY when the
# call exited non-zero AND wrote something to stderr — a real tool failure, never a clean "not
# installed"/"not active" answer (which exits non-zero with empty stderr). detect_supervisor reads
# the flag right after calling the probe, so a probe that could not answer routes to "unclear",
# never silently becomes "none".
#
# "installed": a unit FILE by this name exists, regardless of its current state — the systemd
# analogue of the plist file existing on disk. `list-unit-files` reads unit definitions without
# depending on runtime state, so this stays read-only and safe under --check.
systemd_installed() {
command -v systemctl >/dev/null 2>&1 \
&& systemctl --user list-unit-files "$SYSTEMD_UNIT.service" --no-legend 2>/dev/null | grep -q .
SYSTEMD_INSTALLED_ERRORED=0
command -v systemctl >/dev/null 2>&1 || return 1
local err_file out rc=0
if ! err_file="$(mktemp -t systemd-installed-err)"; then
SYSTEMD_INSTALLED_ERRORED=1
return 1
fi
out="$(systemctl --user list-unit-files "$SYSTEMD_UNIT.service" --no-legend 2>"$err_file")" || rc=$?
if [ "$rc" -ne 0 ]; then
if [ -s "$err_file" ]; then
SYSTEMD_INSTALLED_ERRORED=1
fi
rm -f "$err_file"
return "$rc"
fi
rm -f "$err_file"
printf '%s' "$out" | grep -q .
}
# "loaded": systemd currently supervises this unit as an active job — the systemd analogue of
# `launchctl list <label>` succeeding. Measured on the second host: `systemctl --user is-active
# fleetd` -> "active".
# fleetd` -> "active". A clean "no" (inactive/failed/activating/deactivating) exits non-zero with
# nothing on stderr; a probe that could not reach systemd at all exits non-zero WITH a stderr
# message — see the fleetd #492 follow-up note above.
systemd_loaded() {
command -v systemctl >/dev/null 2>&1 && systemctl --user is-active "$SYSTEMD_UNIT" >/dev/null 2>&1
SYSTEMD_LOADED_ERRORED=0
command -v systemctl >/dev/null 2>&1 || return 1
local err_file rc=0
if ! err_file="$(mktemp -t systemd-loaded-err)"; then
SYSTEMD_LOADED_ERRORED=1
return 1
fi
systemctl --user is-active "$SYSTEMD_UNIT" >/dev/null 2>"$err_file" || rc=$?
if [ "$rc" -ne 0 ] && [ -s "$err_file" ]; then
SYSTEMD_LOADED_ERRORED=1
fi
rm -f "$err_file"
return "$rc"
}
# fleetd #492: three real answers, not two — launchd, systemd, or genuinely unsupervised — plus a
# fourth, "ambiguous", for the one case this script cannot tell apart: both signals firing at once.
# That is exactly "I cannot tell who supervises this process", and guessing wrong here is how two
# daemons end up running against one herdr session (see trap 7 in the header). Pure and
# side-effect-free: reads the two probes above and decides — never mutates anything, so it is safe
# under --check and testable by overriding launchd_loaded/systemd_loaded after sourcing.
# daemons end up running against one herdr session (see trap 7 in the header).
#
# fleetd #492 follow-up: a fifth answer, "unclear", for two more situations that must NEVER be read
# as "none" (measured — see the report this ticket is a follow-up to):
# - installed-but-not-loaded, on EITHER supervisor. `systemctl --user is-active` answers "no" for
# `activating`, `deactivating`, `failed`, and while an auto-restart is pending — every one of
# those is a host that IS under systemd (or launchd) and whose supervisor is about to act again.
# `*_installed` already knows the unit/agent exists; this is the first place that fact is
# actually consulted in the decision, not just printed as a warning.
# - a probe that could not answer at all. systemd_loaded/systemd_installed set their own
# *_ERRORED flag (see the comment above them) when `systemctl` exits non-zero WITH a stderr
# message — a real tool failure, e.g. it cannot reach the user bus over a non-lingering ssh
# session — never conflated with a clean negative answer.
# "none" now means only: neither supervisor is installed, neither is loaded, and neither probe
# errored.
#
# fleetd #492 follow-up — constraints every caller of this function depends on (learned the hard
# way: an earlier version of this fix set a SUPERVISOR_UNCLEAR_DETAIL global from inside here and
# it was silently lost, because every real call site invokes this as `$(detect_supervisor)`):
# 1. It is called as `$(detect_supervisor)`, so ONLY STDOUT crosses back to the caller. Anything
# this function needs to tell its caller — the "unclear" detail included — must be printed,
# never assigned to a global: a global set inside a `$( )` subshell dies with that subshell.
# This function packs BOTH values (kind and detail) onto that one stdout line, joined by
# $SUPERVISOR_DETAIL_SEP, and the caller unpacks them on its own side of the subshell boundary.
# 2. This script runs under `set -euo pipefail` (line 50), so an unset variable is a loud
# failure. Do not add a `${VAR:-default}` anywhere downstream to paper over a value that
# should always be there — that hides a lost value instead of surfacing it (fleetd #497's
# defect class).
# 3. Every `case` on this function's return value needs an explicit final `*)` arm, chosen by
# whether that caller ACTS on the value (`die` — an unrecognised value must never be silently
# driven) or only DISPLAYS it (`echo`/`warn` and continue — a diagnostic must not go silent on
# exactly the value it most needs to report).
#
# Pure and side-effect-free besides the two *_ERRORED flags (read back within this same call, never
# by the caller — see the constraints above): reads the four probes and decides — never mutates
# anything, so it is safe under --check and testable by overriding
# launchd_installed/launchd_loaded/systemd_installed/systemd_loaded after sourcing.
detect_supervisor() {
local ld=0 sd=0
local ld=0 sd=0 li=0 si=0 kind detail=""
SYSTEMD_LOADED_ERRORED=0
SYSTEMD_INSTALLED_ERRORED=0
launchd_loaded && ld=1
systemd_loaded && sd=1
if [ "$ld" = 1 ] && [ "$sd" = 1 ]; then
echo "ambiguous"
launchd_installed && li=1
systemd_installed && si=1
if [ "$SYSTEMD_LOADED_ERRORED" = 1 ] || [ "$SYSTEMD_INSTALLED_ERRORED" = 1 ]; then
detail="the systemd --user probe for '$SYSTEMD_UNIT' could not answer cleanly (systemctl exited non-zero and reported an error on stderr, not a clean negative — e.g. it cannot reach the user bus)"
kind="unclear"
elif [ "$ld" = 1 ] && [ "$sd" = 1 ]; then
kind="ambiguous"
elif [ "$li" = 1 ] && [ "$ld" = 0 ]; then
detail="the launchd agent ($LAUNCHD_LABEL) is installed ($LAUNCHD_PLIST exists) but is not currently loaded"
kind="unclear"
elif [ "$si" = 1 ] && [ "$sd" = 0 ]; then
detail="the systemd --user unit ($SYSTEMD_UNIT) is installed but not currently active — it may be activating, deactivating, failed, or waiting on an auto-restart"
kind="unclear"
elif [ "$ld" = 1 ]; then
echo "launchd"
kind="launchd"
elif [ "$sd" = 1 ]; then
echo "systemd"
kind="systemd"
else
echo "none"
kind="none"
fi
printf '%s%s%s' "$kind" "$SUPERVISOR_DETAIL_SEP" "$detail"
}
# fleetd #492: turns anything detect_supervisor returns that is NOT exactly one of the two
@@ -150,6 +267,19 @@ require_drivable_supervisor() {
OLD jar out from under it — the exact failure this ticket (fleetd #492) exists to
prevent. Stop one of the two supervisors by hand, confirm only one remains loaded, then
rerun." ;;
unclear)
# fleetd #492 follow-up: SUPERVISOR_UNCLEAR_DETAIL crosses back from detect_supervisor's
# subshell via its stdout, unpacked by the caller BEFORE it calls this function (see the
# constraints comment above detect_supervisor). No ${VAR:-default} here on purpose: if the
# detail is somehow missing, `set -u` makes this reference fail loudly instead of silently
# naming nothing — a default that hides a lost value is the same defect class as fleetd
# #497.
die "a supervisor looks present but this script cannot tell whether it actually drives this
daemon: $SUPERVISOR_UNCLEAR_DETAIL. Guessing wrong here is the same failure 'ambiguous'
above exists to prevent: driving the daemon while an unseen supervisor revives the OLD
jar out from under it (fleetd #492). Check 'launchctl list $LAUNCHD_LABEL' and
'systemctl --user status $SYSTEMD_UNIT' by hand, resolve whichever looks unclear, then
rerun." ;;
*)
die "detect_supervisor returned an unrecognized value '$kind' — refusing to guess which
supervisor, if any, controls this daemon." ;;
@@ -301,7 +431,12 @@ fi
# outright — before touching anything — if that cannot be told apart (see require_drivable_
# supervisor above). --check reaches this same line, so a host with an undrivable supervisor is
# reported as a failure even in --check, without ever reaching the build/stop/start steps.
SUPERVISOR_KIND="$(detect_supervisor)"
# fleetd #492 follow-up: detect_supervisor runs as $(...), so only the printed line survives —
# unpack kind and detail from it HERE, in this shell, before calling anything downstream. See the
# constraints comment above detect_supervisor for why this cannot be done any other way.
SUPERVISOR_RAW="$(detect_supervisor)"
SUPERVISOR_KIND="${SUPERVISOR_RAW%%"$SUPERVISOR_DETAIL_SEP"*}"
SUPERVISOR_UNCLEAR_DETAIL="${SUPERVISOR_RAW#*"$SUPERVISOR_DETAIL_SEP"}"
require_drivable_supervisor "$SUPERVISOR_KIND"
ok "supervisor detected: $SUPERVISOR_KIND"
SUPERVISED=0
@@ -320,6 +455,13 @@ case "$SUPERVISOR_KIND" in
none)
warn "no supervisor loaded — this script is the only thing that will restart the daemon."
;;
*)
# fleetd #492 follow-up: this block only DISPLAYS state, it changes nothing yet — so a value
# it doesn't recognise gets reported, not an abort that goes silent on exactly the state most
# worth seeing. (Unreachable today: require_drivable_supervisor above already died on
# "ambiguous"/"unclear" before this case runs. Guards the value nobody has invented yet.)
warn "unrecognised supervisor kind: '$SUPERVISOR_KIND' — detect_supervisor returned a value this block does not know; continuing to report the rest of the state."
;;
esac
# The trap with no log line. Checked in a LOGIN shell, because that is how the daemon is started
@@ -434,6 +576,14 @@ if [ -n "$OLD_PID" ]; then
none)
kill "$OLD_PID"
;;
*)
# fleetd #492 follow-up: this block ACTS (stops the daemon one specific way per kind) — an
# unrecognised value must never fall through to a default action, silently picking the wrong
# one (or none at all) while reporting success. (Unreachable today: require_drivable_
# supervisor already died before this runs. Guards the value nobody has invented yet.)
die "detect_supervisor returned an unrecognized value '$SUPERVISOR_KIND' at the stop step —
refusing to guess how to stop a daemon under an unknown supervisor. The daemon was NOT
stopped." ;;
esac
for _ in $(seq "$STOP_WAIT"); do
[ -z "$(running_pid)" ] && break
@@ -507,6 +657,14 @@ case "$SUPERVISOR_KIND" in
# Absolute jar path so `ps` names which checkout is running.
( cd "$MODULE" && zsh -lc "nohup java -jar '$JAR' >> fleetd.out 2>&1 &" )
;;
*)
# fleetd #492 follow-up: this block ACTS (starts the daemon one specific way per kind) — an
# unrecognised value must never fall through to a default action, silently picking the wrong
# one (or none at all) while reporting success. (Unreachable today: require_drivable_
# supervisor already died before this runs. Guards the value nobody has invented yet.)
die "detect_supervisor returned an unrecognized value '$SUPERVISOR_KIND' at the start step —
refusing to guess how to start a daemon under an unknown supervisor. The daemon was NOT
started." ;;
esac
for _ in $(seq 10); do
+116 -3
View File
@@ -25,6 +25,17 @@ classify_fixture() {
classify_amqp_connection_errors "$TMP/$name"
}
# fleetd #492 follow-up: detect_supervisor's stdout is now "kind<SEP>detail" (see the constraints
# comment above detect_supervisor in redeploy-fleetd.sh) — every test below that only cares about
# the kind must split it out with the SAME in-shell parameter expansion the real call site (:438)
# uses, never a bare string comparison against the raw output.
supervisor_kind_of() {
printf '%s' "${1%%"$SUPERVISOR_DETAIL_SEP"*}"
}
supervisor_detail_of() {
printf '%s' "${1#*"$SUPERVISOR_DETAIL_SEP"}"
}
# fleetd #492 — supervisor detection. Detect_supervisor() reads launchd_loaded/systemd_loaded, so
# each test overrides BOTH pairs (installed + loaded) explicitly, rather than relying on either
@@ -37,7 +48,7 @@ test_detect_supervisor_launchd_only() {
launchd_loaded() { return 0; }
systemd_installed() { return 1; }
systemd_loaded() { return 1; }
assert_equals "launchd" "$(detect_supervisor)" "launchd-only detection"
assert_equals "launchd" "$(supervisor_kind_of "$(detect_supervisor)")" "launchd-only detection"
}
test_detect_supervisor_systemd_only() {
@@ -45,7 +56,7 @@ test_detect_supervisor_systemd_only() {
launchd_loaded() { return 1; }
systemd_installed() { return 0; }
systemd_loaded() { return 0; }
assert_equals "systemd" "$(detect_supervisor)" "systemd-only detection"
assert_equals "systemd" "$(supervisor_kind_of "$(detect_supervisor)")" "systemd-only detection"
}
test_detect_supervisor_none() {
@@ -53,7 +64,105 @@ test_detect_supervisor_none() {
launchd_loaded() { return 1; }
systemd_installed() { return 1; }
systemd_loaded() { return 1; }
assert_equals "none" "$(detect_supervisor)" "unsupervised detection"
assert_equals "none" "$(supervisor_kind_of "$(detect_supervisor)")" "unsupervised detection"
}
# fleetd #492 follow-up — detect_supervisor must never answer "none" when the truth is "could not
# tell". `systemd_installed`/`systemd_loaded` already know a unit file exists; this proves that
# fact is now actually consulted, not just printed as a warning: an installed-but-not-loaded unit
# reads as unclear, because is-active answers "no" for activating/deactivating/failed/pending
# auto-restart too, and every one of those is a host that IS under systemd.
test_detect_supervisor_systemd_installed_not_loaded_is_unclear() {
launchd_installed() { return 1; }
launchd_loaded() { return 1; }
systemd_installed() { return 0; } # the unit file IS there
systemd_loaded() { return 1; } # is-active says no — could be activating/failed/pending restart
local raw
raw="$(detect_supervisor)"
assert_equals "unclear" "$(supervisor_kind_of "$raw")" "systemd installed-but-not-loaded must read as unclear, not none"
printf '%s' "$(supervisor_detail_of "$raw")" | grep -qF "$SYSTEMD_UNIT" \
|| fail "detail does not name the systemd unit it found installed-but-not-loaded"
}
# Same fact, the launchd side: a plist on disk that is not currently loaded (unloaded without being
# removed, or about to be reloaded) must not read as "no supervisor" either.
test_detect_supervisor_launchd_installed_not_loaded_is_unclear() {
launchd_installed() { return 0; } # the plist IS there
launchd_loaded() { return 1; } # launchctl list says not loaded
systemd_installed() { return 1; }
systemd_loaded() { return 1; }
local raw
raw="$(detect_supervisor)"
assert_equals "unclear" "$(supervisor_kind_of "$raw")" "launchd installed-but-not-loaded must read as unclear, not none"
printf '%s' "$(supervisor_detail_of "$raw")" | grep -qF "$LAUNCHD_LABEL" \
|| fail "detail does not name the launchd label it found installed-but-not-loaded"
}
# Drives the REAL systemd_loaded/systemd_installed bodies (never stubbed) through a `systemctl`
# stub placed first on PATH that exits non-zero AND writes to stderr — the shape of a systemctl
# that runs but cannot reach the user bus (measured elsewhere as a headless ssh session with no
# lingering). This must read as unclear, never none: a probe that could not answer at all is not
# the same fact as "no supervisor is loaded".
test_detect_supervisor_systemd_probe_error_is_unclear() {
# Re-source first to restore the REAL launchd_*/systemd_* probe bodies. Earlier tests in this
# file permanently override them with stub `return 0`/`return 1` bodies (that is the whole point
# of those tests), and a bash function definition is global for the rest of the process — without
# this, systemd_loaded here would still be whatever the previous test left it as, never touching
# a real `systemctl` call at all.
source "$ROOT/scripts/redeploy-fleetd.sh"
local bin_dir result rc=0
bin_dir="$TMP/stub-bin-systemctl-errors"
mkdir -p "$bin_dir"
cat > "$bin_dir/systemctl" <<'STUB'
#!/usr/bin/env bash
echo "Failed to connect to bus: No such file or directory" >&2
exit 1
STUB
chmod +x "$bin_dir/systemctl"
PATH="$bin_dir:$PATH" systemd_loaded && rc=0 || rc=$?
[ "$rc" -ne 0 ] || fail "systemd_loaded must not report loaded=true when systemctl only errored"
assert_equals "1" "$SYSTEMD_LOADED_ERRORED" "systemd_loaded must flag a probe error, not a clean negative"
launchd_installed() { return 1; }
launchd_loaded() { return 1; }
result="$(PATH="$bin_dir:$PATH" detect_supervisor)"
assert_equals "unclear" "$(supervisor_kind_of "$result")" "a systemd probe error must read as unclear, not none"
printf '%s' "$(supervisor_detail_of "$result")" | grep -qF "$SYSTEMD_UNIT" \
|| fail "detail does not name the systemd unit whose probe errored"
}
# fleetd #492 follow-up (Item 1): this must go through the REAL call-site shape at :437-440, not a
# hand-constructed "unclear" value — a test that builds "unclear" directly proves the switch, not
# the handoff, and that is exactly the gap that let SUPERVISOR_UNCLEAR_DETAIL never reach the real
# caller in b17f37a. detect_supervisor runs as $(detect_supervisor): a subshell. Only stdout
# survives that boundary, so kind AND detail must both cross on it — this test proves they do.
test_require_drivable_supervisor_refuses_unclear() {
launchd_installed() { return 1; }
launchd_loaded() { return 1; }
systemd_installed() { return 0; }
systemd_loaded() { return 1; }
local SUPERVISOR_RAW SUPERVISOR_KIND SUPERVISOR_UNCLEAR_DETAIL output rc=0
# Exactly what :437-439 does — do not shortcut this by constructing "unclear" by hand.
SUPERVISOR_RAW="$(detect_supervisor)"
SUPERVISOR_KIND="${SUPERVISOR_RAW%%"$SUPERVISOR_DETAIL_SEP"*}"
SUPERVISOR_UNCLEAR_DETAIL="${SUPERVISOR_RAW#*"$SUPERVISOR_DETAIL_SEP"}"
assert_equals "unclear" "$SUPERVISOR_KIND" "setup: expected unclear before testing the refusal"
[ -n "$SUPERVISOR_UNCLEAR_DETAIL" ] \
|| fail "detail did not survive the \$(...) call-site boundary — SUPERVISOR_UNCLEAR_DETAIL is empty in the parent shell"
printf '%s' "$SUPERVISOR_UNCLEAR_DETAIL" | grep -qF "$SYSTEMD_UNIT" \
|| fail "detail that crossed the subshell boundary does not name the systemd unit it found installed-but-not-loaded"
output="$(require_drivable_supervisor "$SUPERVISOR_KIND" 2>&1)" || rc=$?
[ "$rc" -ne 0 ] || fail "require_drivable_supervisor accepted an unclear (undrivable) supervisor"
# Check for the ACTUAL DETAIL TEXT, not just "$SYSTEMD_UNIT" — the die() message's boilerplate
# recovery instructions name the unit unconditionally either way ("systemctl --user status
# $SYSTEMD_UNIT"), so a bare unit-name grep here would pass even on a lost/fallback detail. Only
# the specific detail string proves the crossed value, not the boilerplate, reached the message.
printf '%s' "$output" | grep -qF "$SUPERVISOR_UNCLEAR_DETAIL" \
|| fail "refusal message does not contain the specific detail that crossed the subshell boundary"
}
# The heart of the ticket: a supervisor this script cannot drive must refuse, never fall through to
@@ -299,7 +408,11 @@ test_unattributable_quiet_mutation_is_caught() {
test_detect_supervisor_launchd_only
test_detect_supervisor_systemd_only
test_detect_supervisor_none
test_detect_supervisor_systemd_installed_not_loaded_is_unclear
test_detect_supervisor_launchd_installed_not_loaded_is_unclear
test_detect_supervisor_systemd_probe_error_is_unclear
test_require_drivable_supervisor_refuses_ambiguous
test_require_drivable_supervisor_refuses_unclear
test_require_drivable_supervisor_accepts_known_kinds
test_count_daemon_pids
test_assert_single_daemon_accepts_one_pid