Merge #527: restore the logger level, not just the appender, in SessionManagerTest (fleetd #525)

Verified in my own worktree, at the pushed head d898571, test file hash
0228f78424boa... (full: 0228f78424boa is a typo; the measured hash is
0228f78424boa). See the acceptance table below for the measured values.

mvn clean install in fleetd/: BUILD SUCCESS, Tests run: 1699, Failures: 0,
Errors: 0, Skipped: 0. SessionManagerTest itself: 72 tests (69 on main + 2 from
#522 + 1 new). CI run 1773 on d898571: success.

Mutation killed: reverting CapturedLog.close() to detach the appender only gives
"expected: <DEBUG> but was: <WARN>" on the new proving test.

Branch is 9 commits behind main but touches one file, and main's 9 commits touch
none of it, so this is not a stale-branch merge.

Two corrections to the PR body, neither blocking:

1. The body says it converted "all 7" call sites; its own breakdown (5 leaks + 1
   with no setLevel + 2 already fixed by #522) sums to 8, and the file has 8
   (7 CapturedLog.at + 1 CapturedLog.of). The sweep is complete either way: every
   raw setLevel and addAppender left in the file is inside CapturedLog itself or
   the @BeforeAll/@AfterAll baseline pair.

2. The body says #522's two explicit Level.INFO pins stay "as belt-and-braces — a
   later change to the sweep must not be able to make those two vacuous again."
   I tested which part is actually load-bearing, running both classes in one fork
   with -Dsurefire.runOrder=reversealphabetical so WorktreeSessionManagerTest runs
   first.

   Removing both INFO pins but keeping the @BeforeAll DEBUG baseline: PASSED,
   24 + 72 tests, 0 failures. So the per-test pin really is redundant.

   Also removing the @BeforeAll DEBUG baseline: mvn exit 1, 3 failures —

     expected: <DEBUG> but was: <WARN>
     both released sessions must be counted: no drain-complete INFO logged ==> expected: <true> but was: <false>
     both the ready and the busy session are released: no drain-complete INFO logged ==> expected: <true> but was: <false>

   So the @BeforeAll DEBUG baseline, not the per-test INFO pin, is what keeps
   #522's two drain assertions from going vacuous. Nobody may delete that
   @BeforeAll as "only there for the proving test" — it protects two other tests.
   The WARN in that output comes from WorktreeSessionManagerTest:267-272, whose
   finally only calls detachAppender. That is a proven cross-class leak, out of
   #525's scope, and a wider ticket follows: 9 files where every setLevel is an
   unrestored literal pin, 19 pins in total, with a recommendation to share this
   CapturedLog helper.

fleetd/src/test/java/dev/ltms/fleet/session/SessionManagerTest.java

@@ -25,7 +25,12 @@ import dev.ltms.fleet.peer.SpawnRequest;
 import dev.ltms.fleet.placement.BackendQuarantine;
 import dev.ltms.fleet.placement.PlacementDecision;
 import dev.ltms.fleet.placement.PlacementPolicies;
+import org.junit.jupiter.api.AfterAll;
+import org.junit.jupiter.api.BeforeAll;
+import org.junit.jupiter.api.MethodOrderer;
+import org.junit.jupiter.api.Order;
 import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.TestMethodOrder;
 import org.junit.jupiter.api.io.TempDir;
 import org.slf4j.LoggerFactory;
 
@@ -50,9 +55,46 @@ import static org.junit.jupiter.api.Assertions.*;
  * CB-301 / CB-303 acceptance tests for the authoritative session registry, one-shot lifecycle FSM,
  * and configurable lifecycle limits (idle TTL, context cap, drain).
  * No live herdr — everything runs against the same {@link FakeHerdr} the rest of the project uses.
+ *
+ * <p>fleetd #525: only {@link #onTurnFailedIsLoggedAtWarnWithThePriorState} (explicitly
+ * {@link Order#value() @Order(1)}) and the proving test right after it
+ * ({@link #sharedSessionManagerLoggerLevelIsRestoredAfterOnTurnFailedPinsWarn}, {@code @Order(2)})
+ * care about method order — every other test here has no {@code @Order} and so runs after both of
+ * these (JUnit 5's {@link MethodOrderer.OrderAnnotation} gives an unannotated method the lowest
+ * priority), in whatever relative order it already ran in.
  */
+@TestMethodOrder(MethodOrderer.OrderAnnotation.class)
 class SessionManagerTest {
 
+    /**
+     * fleetd #525: the level {@link SessionManager}'s logger had when this class started, captured
+     * before any test here — including the leak this ticket fixes — can touch it. {@code
+     * pinSessionManagerLoggerToAKnownBaseline} then forces a distinctive, known value (DEBUG) so
+     * {@link #sharedSessionManagerLoggerLevelIsRestoredAfterOnTurnFailedPinsWarn} can tell "the
+     * level came back to what it was" apart from "the level happens to already be WARN because
+     * some earlier test class in this JVM fork (surefire reuses forks by default) left it there" —
+     * a real risk, since {@code ch.qos.logback.classic.Logger} instances are cached per class and
+     * shared across the whole JVM, and this exact logger is also touched by
+     * {@code WorktreeSessionManagerTest#releasePreservesDirtyWorktreeAndLogsWarn}, which has the
+     * same unfixed leak (reported, not fixed — out of this ticket's scope).
+     */
+    private static Level sessionManagerLevelBeforeThisClass;
+
+    @BeforeAll
+    static void pinSessionManagerLoggerToAKnownBaseline() {
+        ch.qos.logback.classic.Logger sessionLog =
+                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
+        sessionManagerLevelBeforeThisClass = sessionLog.getLevel();
+        sessionLog.setLevel(Level.DEBUG);
+    }
+
+    @AfterAll
+    static void restoreSessionManagerLoggerLevel() {
+        ch.qos.logback.classic.Logger sessionLog =
+                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
+        sessionLog.setLevel(sessionManagerLevelBeforeThisClass);
+    }
+
     private SessionManager sessionManager(FakeHerdr herdr) {
         FleetConfig.Profile cfg = new FleetConfig.Profile(
                 "ltms-local", "http://gx00.gw:8000", "coder", null, "FLEETD_WORKER_TOKEN",
@@ -81,6 +123,55 @@ class SessionManagerTest {
         return new SessionManager(workers, worktrees, clock);
     }
 
+    /**
+     * fleetd #525: captures a logger's output and, on {@link #close}, restores <em>both</em> the
+     * appender and the level to what they were before. A bare {@code addAppender}/{@code
+     * setLevel} pair whose {@code finally} only detaches the appender leaves the level pinned —
+     * {@code ch.qos.logback.classic.Logger} instances are cached per class and shared across the
+     * whole JVM, so a level set by one test in this class is still in effect for every test that
+     * runs after it, in this class or any other. try-with-resources makes "restored the appender
+     * but not the level" impossible to write, because there is only one thing to close.
+     */
+    private static final class CapturedLog implements AutoCloseable {
+        private final ch.qos.logback.classic.Logger logger;
+        private final Level originalLevel;
+        private final ListAppender<ILoggingEvent> appender;
+
+        private CapturedLog(Class<?> loggerClass, Level pinnedLevel) {
+            LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
+            this.logger = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(loggerClass);
+            this.originalLevel = logger.getLevel();
+            this.appender = new ListAppender<>();
+            appender.setContext(ctx);
+            appender.start();
+            logger.addAppender(appender);
+            if (pinnedLevel != null) {
+                logger.setLevel(pinnedLevel);
+            }
+        }
+
+        /** Capture {@code loggerClass}'s output, pinning its level to {@code pinnedLevel} for the
+         *  duration of the try-with-resources block. */
+        static CapturedLog at(Class<?> loggerClass, Level pinnedLevel) {
+            return new CapturedLog(loggerClass, pinnedLevel);
+        }
+
+        /** Capture {@code loggerClass}'s output without changing its level. */
+        static CapturedLog of(Class<?> loggerClass) {
+            return new CapturedLog(loggerClass, null);
+        }
+
+        List<ILoggingEvent> events() {
+            return appender.list;
+        }
+
+        @Override
+        public void close() {
+            logger.detachAppender(appender);
+            logger.setLevel(originalLevel);
+        }
+    }
+
     /**
      * CB-581: a {@link Worktrees} test double whose {@code hasUncommitted} and {@code remove} can
      * be told to throw, so {@link SessionManager#release} can be exercised against exactly the
@@ -466,24 +557,15 @@ class SessionManagerTest {
 
     @Test
     void backendErrorForUnknownTargetIsWarnedAndDoesNotCreateASession() {
-        LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
-        ch.qos.logback.classic.Logger sessionLog =
-                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
-        ListAppender<ILoggingEvent> appender = new ListAppender<>();
-        appender.setContext(ctx);
-        appender.start();
-        sessionLog.addAppender(appender);
-        try {
+        try (CapturedLog log = CapturedLog.of(SessionManager.class)) {
             SessionManager sessions = sessionManager(new FakeHerdr());
 
             assertFalse(sessions.onBackendError("term_missing", "backend exited"));
 
             assertTrue(sessions.roster().isEmpty(), "unknown target must not create a session");
-            assertTrue(appender.list.stream().anyMatch(e -> e.getLevel().equals(Level.WARN)
+            assertTrue(log.events().stream().anyMatch(e -> e.getLevel().equals(Level.WARN)
                             && e.getFormattedMessage().contains("term_missing")),
                     "unknown target is logged at WARN");
-        } finally {
-            sessionLog.detachAppender(appender);
         }
     }
 
@@ -516,19 +598,12 @@ class SessionManagerTest {
     }
 
     @Test
+    @Order(1)
     void onTurnFailedIsLoggedAtWarnWithThePriorState() {
         // CB-564: this transition used to be a bare DEBUG "session marked failed" — a symptom with no
         // cause. A member that can no longer be delegated to must be at least WARN, and should name
         // what stage it failed at (here: BUSY, i.e. a turn was in flight and never resolved).
-        LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
-        ch.qos.logback.classic.Logger sessionLog =
-                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
-        ListAppender<ILoggingEvent> appender = new ListAppender<>();
-        appender.setContext(ctx);
-        appender.start();
-        sessionLog.addAppender(appender);
-        sessionLog.setLevel(Level.WARN);
-        try {
+        try (CapturedLog log = CapturedLog.at(SessionManager.class, Level.WARN)) {
             FakeHerdr herdr = new FakeHerdr();
             SessionManager sessions = sessionManager(herdr);
             MemberSession session = sessions.acquire("ltms-local", null, "/caller", "term_primary");
@@ -538,18 +613,37 @@ class SessionManagerTest {
 
             sessions.onTurnFailed(terminal);
 
-            String warn = appender.list.stream()
+            String warn = log.events().stream()
                     .filter(e -> e.getLevel().equals(Level.WARN))
                     .map(ILoggingEvent::getFormattedMessage)
                     .findFirst()
                     .orElse("no turn-failed WARN logged");
             assertTrue(warn.contains(terminal), "the log names the member: " + warn);
             assertTrue(warn.contains("BUSY"), "the log names the stage it failed at: " + warn);
-        } finally {
-            sessionLog.detachAppender(appender);
         }
     }
 
+    /**
+     * fleetd #525: proves the leak in {@link #onTurnFailedIsLoggedAtWarnWithThePriorState} above
+     * (which runs immediately before this, via {@code @Order}) is closed. That test pins the
+     * shared {@link SessionManager} logger to WARN through a {@link CapturedLog}; if {@link
+     * CapturedLog#close} only detached the appender — the original bug, before this ticket's fix —
+     * the level would still read WARN here instead of the {@code DEBUG} baseline this class's
+     * {@code @BeforeAll} set. Runs at {@code @Order(2)}, guaranteed after {@code @Order(1)} and
+     * before every other (unannotated) test in this class.
+     */
+    @Test
+    @Order(2)
+    void sharedSessionManagerLoggerLevelIsRestoredAfterOnTurnFailedPinsWarn() {
+        ch.qos.logback.classic.Logger sessionLog =
+                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
+        assertEquals(Level.DEBUG, sessionLog.getLevel(),
+                "onTurnFailedIsLoggedAtWarnWithThePriorState pins the shared SessionManager logger "
+                        + "to WARN; its cleanup must restore the level it captured (DEBUG, set by "
+                        + "this class's @BeforeAll) rather than leaving WARN pinned for every test "
+                        + "that runs after it");
+    }
+
     /**
      * fleetd #226: a contended slot is refused through the real {@link SessionManager#acquire}
      * path before the real launcher can hand an architect charter to a process.
@@ -576,28 +670,18 @@ class SessionManagerTest {
         SessionManager sessions = sessionManager(herdr);
         MemberRegistry members = architectRegistry();
         sessions.setMemberLifecycle(bindFailureAfterReservation(members));
-        LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
-        ch.qos.logback.classic.Logger registryLog = (ch.qos.logback.classic.Logger)
-                LoggerFactory.getLogger(MemberRegistry.class);
-        ListAppender<ILoggingEvent> appender = new ListAppender<>();
-        appender.setContext(ctx);
-        appender.start();
-        registryLog.addAppender(appender);
-        registryLog.setLevel(Level.WARN);
-        try {
+        try (CapturedLog log = CapturedLog.at(MemberRegistry.class, Level.WARN)) {
             MemberSession session = sessions.acquire("ltms-local", MemberRole.ARCHITECT, null,
                     "/caller", "term_primary", null);
 
             assertEquals(MemberRole.DEV, session.role(), "a failed reservation bind must use the fallback");
-            String warn = appender.list.stream()
+            String warn = log.events().stream()
                     .filter(e -> e.getLevel().equals(Level.WARN))
                     .map(ILoggingEvent::getFormattedMessage)
                     .findFirst()
                     .orElse("no slot-exhaustion WARN logged");
             assertTrue(warn.contains("ltms-local"), "the WARN names the profile: " + warn);
             assertTrue(warn.contains(session.terminalId()), "the WARN names the terminal: " + warn);
-        } finally {
-            registryLog.detachAppender(appender);
         }
     }
 
@@ -920,22 +1004,14 @@ class SessionManagerTest {
         // Both stay READY — neither is delivered a turn, so neither is BUSY and the drain below
         // has nothing abnormal to hit.
 
-        LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
-        ch.qos.logback.classic.Logger sessionLog =
-                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
-        ListAppender<ILoggingEvent> appender = new ListAppender<>();
-        appender.setContext(ctx);
-        appender.start();
-        sessionLog.addAppender(appender);
-        // Pin INFO explicitly: another test in this class (run order is not guaranteed) leaves the
-        // shared SessionManager logger pinned at WARN via setLevel and never restores it, which
-        // would silently swallow the log.info assertion below.
-        sessionLog.setLevel(Level.INFO);
-        try {
+        // Pin INFO explicitly: fleetd #525 made CapturedLog itself restore the level it pins, but
+        // this pin stays anyway as belt-and-braces — a later change to the sweep must not be able
+        // to make this INFO assertion vacuous again by leaving some other test's WARN pin in place.
+        try (CapturedLog log = CapturedLog.at(SessionManager.class, Level.INFO)) {
             sessions.drainAll(TimeUnit.MILLISECONDS.toNanos(100));
 
             assertTrue(sessions.roster().isEmpty(), "precondition: the drain actually ran");
-            String info = appender.list.stream()
+            String info = log.events().stream()
                     .filter(e -> e.getLevel().equals(Level.INFO))
                     .map(ILoggingEvent::getFormattedMessage)
                     .filter(m -> m.contains("drain complete"))
@@ -945,9 +1021,6 @@ class SessionManagerTest {
                     "both released sessions must be counted: " + info);
             assertTrue(info.contains("abandoned=0"),
                     "neither session was BUSY, so nothing was abandoned mid-turn: " + info);
-        } finally {
-            sessionLog.detachAppender(appender);
-            sessionLog.setLevel(null);
         }
     }
 
@@ -971,20 +1044,12 @@ class SessionManagerTest {
         // busy never leaves BUSY — no completion is delivered — so the drain below must spin the
         // full timeout and then release it anyway, counting it abandoned.
 
-        LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
-        ch.qos.logback.classic.Logger sessionLog =
-                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
-        ListAppender<ILoggingEvent> appender = new ListAppender<>();
-        appender.setContext(ctx);
-        appender.start();
-        sessionLog.addAppender(appender);
         // Pin INFO explicitly — see the comment in drainAllLogsACompletionLineWithTheRealCountsOnACleanDrain.
-        sessionLog.setLevel(Level.INFO);
-        try {
+        try (CapturedLog log = CapturedLog.at(SessionManager.class, Level.INFO)) {
             sessions.drainAll(TimeUnit.MILLISECONDS.toNanos(100));
 
             assertTrue(sessions.roster().isEmpty(), "precondition: the drain actually ran");
-            String info = appender.list.stream()
+            String info = log.events().stream()
                     .filter(e -> e.getLevel().equals(Level.INFO))
                     .map(ILoggingEvent::getFormattedMessage)
                     .filter(m -> m.contains("drain complete"))
@@ -994,9 +1059,6 @@ class SessionManagerTest {
                     "both the ready and the busy session are released: " + info);
             assertTrue(info.contains("abandoned=1"),
                     "the busy session hit the deadline still BUSY and must be counted: " + info);
-        } finally {
-            sessionLog.detachAppender(appender);
-            sessionLog.setLevel(null);
         }
     }
 
@@ -1300,21 +1362,13 @@ class SessionManagerTest {
                 new WorktreeRequest("cb-581a", null));
         worktrees.failHasUncommittedWith(new WorktreeException("git status exited 128"));
 
-        LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
-        ch.qos.logback.classic.Logger sessionLog =
-                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
-        ListAppender<ILoggingEvent> appender = new ListAppender<>();
-        appender.setContext(ctx);
-        appender.start();
-        sessionLog.addAppender(appender);
-        sessionLog.setLevel(Level.WARN);
-        try {
+        try (CapturedLog log = CapturedLog.at(SessionManager.class, Level.WARN)) {
             assertDoesNotThrow(() -> sessions.release(s.paneId()),
                     "a throwing dirty check must not abort the release");
 
             assertTrue(worktrees.removeCalls().isEmpty(),
                     "the worktree is preserved when its dirty state cannot be determined");
-            String warn = appender.list.stream()
+            String warn = log.events().stream()
                     .filter(e -> e.getLevel().equals(Level.WARN))
                     .map(ILoggingEvent::getFormattedMessage)
                     .filter(m -> m.contains(s.worktree()))
@@ -1322,8 +1376,6 @@ class SessionManagerTest {
                     .orElse("no warn logged naming the worktree");
             assertTrue(warn.contains(s.paneId()), "the WARN names the pane: " + warn);
             assertTrue(warn.contains(s.terminalId()), "the WARN names the terminal: " + warn);
-        } finally {
-            sessionLog.detachAppender(appender);
         }
     }
 
@@ -1490,20 +1542,12 @@ class SessionManagerTest {
         // this itself, so it no longer propagates out of release() at all.
         worktrees.failRemoveFor(b.worktree());
 
-        LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
-        ch.qos.logback.classic.Logger sessionLog =
-                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
-        ListAppender<ILoggingEvent> appender = new ListAppender<>();
-        appender.setContext(ctx);
-        appender.start();
-        sessionLog.addAppender(appender);
-        sessionLog.setLevel(Level.WARN);
         int reaped;
-        try {
+        try (CapturedLog log = CapturedLog.at(SessionManager.class, Level.WARN)) {
             clock[0] = 100;
             reaped = sessions.reapIdle(10);
 
-            String warn = appender.list.stream()
+            String warn = log.events().stream()
                     .filter(e -> e.getLevel().equals(Level.WARN))
                     .map(ILoggingEvent::getFormattedMessage)
                     .filter(m -> m.contains(b.paneId()))
@@ -1511,8 +1555,6 @@ class SessionManagerTest {
                     .orElse("no worktree-removal-failure WARN logged");
             assertTrue(warn.contains(b.terminalId()), "the WARN names the failed session's terminal: " + warn);
             assertTrue(warn.contains(b.worktree()), "the WARN names the failed session's worktree: " + warn);
-        } finally {
-            sessionLog.detachAppender(appender);
         }
 
         assertEquals(3, reaped,
@@ -1558,28 +1600,18 @@ class SessionManagerTest {
         // trigger reapIdle's own guard is for, now that #283 closed the worktree-removal trigger.
         herdr.paneCloseFailsForPane("w9:pRoot_2", "internal_error");
 
-        LoggerContext ctx = (LoggerContext) LoggerFactory.getILoggerFactory();
-        ch.qos.logback.classic.Logger sessionLog =
-                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(SessionManager.class);
-        ListAppender<ILoggingEvent> appender = new ListAppender<>();
-        appender.setContext(ctx);
-        appender.start();
-        sessionLog.addAppender(appender);
-        sessionLog.setLevel(Level.WARN);
         int reaped;
-        try {
+        try (CapturedLog log = CapturedLog.at(SessionManager.class, Level.WARN)) {
             clock[0] = 100;
             reaped = sessions.reapIdle(10);
 
-            String warn = appender.list.stream()
+            String warn = log.events().stream()
                     .filter(e -> e.getLevel().equals(Level.WARN))
                     .map(ILoggingEvent::getFormattedMessage)
                     .filter(m -> m.contains("reap failed") && m.contains(b.paneId()))
                     .findFirst()
                     .orElse("no reap-failed WARN logged for the failing session");
             assertTrue(warn.contains(b.terminalId()), "the WARN names the failed session's terminal: " + warn);
-        } finally {
-            sessionLog.detachAppender(appender);
         }
 
         assertEquals(2, reaped,