diff --git a/fleetd/src/main/java/dev/ltms/fleet/lead/LeadRollover.java b/fleetd/src/main/java/dev/ltms/fleet/lead/LeadRollover.java
index b521940..f5c9587 100644
--- a/fleetd/src/main/java/dev/ltms/fleet/lead/LeadRollover.java
+++ b/fleetd/src/main/java/dev/ltms/fleet/lead/LeadRollover.java
@@ -382,13 +382,17 @@ public final class LeadRollover {
private void runRollover(PendingRollover p, FleetConfig.LeadRollover cfg) {
String lead = p.leadTerminal();
long rollStartMillis = nowMillis.getAsLong();
- 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());
+ 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;
}
@@ -483,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 {
@@ -496,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}. fleetd #489 — the paste-race fix.
@@ -587,10 +604,19 @@ public final class LeadRollover {
// 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: the nudge count printed here must be the MEASURED
+ // `nudges` counter, never the constant `PICKUP_GRACE_POLLS - 1` — the constant
+ // happens to equal it today (this branch only fires after exactly
+ // PICKUP_GRACE_POLLS - 1 nudges), but a mutation test caught this exact
+ // expression once already printing the wrong constant (PICKUP_GRACE_POLLS
+ // itself, claiming 8 nudges where 7 went out) and a plain code read did not
+ // catch it. Printing the counter cannot drift from the loop's real behaviour,
+ // whatever changes later to PICKUP_GRACE_POLLS or the loop itself.
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 (elapsed={}ms)",
- target, PICKUP_GRACE_POLLS, PICKUP_GRACE_POLLS - 1, elapsedMillis);
+ target, PICKUP_GRACE_POLLS, nudges, elapsedMillis);
return new ClearSettleResult(true, elapsedMillis, nudges);
}
try {
diff --git a/fleetd/src/test/java/dev/ltms/fleet/lead/LeadRolloverTest.java b/fleetd/src/test/java/dev/ltms/fleet/lead/LeadRolloverTest.java
index 16e021c..cfbc813 100644
--- a/fleetd/src/test/java/dev/ltms/fleet/lead/LeadRolloverTest.java
+++ b/fleetd/src/test/java/dev/ltms/fleet/lead/LeadRolloverTest.java
@@ -971,6 +971,14 @@ class LeadRolloverTest {
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: the nudge count in this line must be the MEASURED counter, not
+ // the constant PICKUP_GRACE_POLLS - 1 that used to stand in for it — the two happen to
+ // agree today, but only the counter cannot drift from the loop's real behaviour if
+ // PICKUP_GRACE_POLLS or the loop ever changes. Reference the constant here (rather than
+ // hardcoding "7") so this assertion itself does not silently stop discriminating if
+ // PICKUP_GRACE_POLLS changes later.
+ assertTrue(message.contains("(" + (LeadRollover.PICKUP_GRACE_POLLS - 1) + " of those were nudged)"),
+ "must print the measured nudge count: " + message);
} finally {
detachLog(events);
}
@@ -1000,9 +1008,53 @@ class LeadRolloverTest {
ILoggingEvent event = lastEventContaining(events, "lead-rollover: rolled");
assertEquals(Level.INFO, event.getLevel());
String message = event.getFormattedMessage();
- assertTrue(message.contains("elapsedMs=6500"), "must print the MEASURED elapsed time for "
+ // 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 6500ms: " + message);
+ + "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 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);
}