diff --git a/bridged/src/main/java/dev/ltms/bridged/inject/Injector.java b/bridged/src/main/java/dev/ltms/bridged/inject/Injector.java index f72b902..4b41660 100644 --- a/bridged/src/main/java/dev/ltms/bridged/inject/Injector.java +++ b/bridged/src/main/java/dev/ltms/bridged/inject/Injector.java @@ -78,6 +78,13 @@ public final class Injector { */ private static final int READINESS_GRACE_POLLS = 240; + /** + * The cadence the poller drives {@link #onStatus} at, matched to {@code Bridged.INJECT_POLL_MILLIS}. + * This class holds no timing itself (it is driven by the poller), so this exists only to state + * the readiness grace in seconds on the CB-562 expiry log instead of hardcoding "60s". + */ + private static final long POLL_INTERVAL_MILLIS = 250; + private final AgentControl agents; private final TurnListener turnListener; private final Predicate ready; // CB-113: a target is deliverable only when available @@ -264,6 +271,11 @@ public final class Injector { // 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); + 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; } diff --git a/bridged/src/test/java/dev/ltms/bridged/inject/InjectorTest.java b/bridged/src/test/java/dev/ltms/bridged/inject/InjectorTest.java index d7e953d..4d9efb5 100644 --- a/bridged/src/test/java/dev/ltms/bridged/inject/InjectorTest.java +++ b/bridged/src/test/java/dev/ltms/bridged/inject/InjectorTest.java @@ -1,10 +1,15 @@ package dev.ltms.bridged.inject; +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; import dev.ltms.bridged.herdr.AgentControl; import dev.ltms.bridged.herdr.AgentStatus; import dev.ltms.bridged.herdr.FakeHerdr; import dev.ltms.bridged.herdr.HerdrException; import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; import java.util.ArrayList; import java.util.List; @@ -369,6 +374,39 @@ class InjectorTest { assertTrue(inj.activeTargets().isEmpty(), "the target is reclaimed, not polled forever"); } + @Test + void readinessGraceExpiryIsLogged() { + // CB-562: the grace-expiry path used to clear the queue silently, so a message that never + // reached the worker's pane surfaced elsewhere as an unrelated turn-stall failure. Assert the + // expiry now names the real cause. (ListAppender capture pattern mirrors AuditLogTest.) + LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory(); + ch.qos.logback.classic.Logger injectorLog = + (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Injector.class); + ListAppender 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"); + + 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(T), "the log names the target terminal: " + warn); + assertTrue(warn.contains("never reached"), "the log names the real cause: " + warn); + assertTrue(warn.contains("1"), "the log carries the failed message count: " + 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