fleetd #529: promote CapturedLog to a shared test helper, close the logger-level leak #533
Reference in New Issue
Block a user
Delete Branch "worker/529-logger-level-sweep-2a5533-8"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Fixes fleetd #529.
The defect
ch.qos.logback.classic.Loggerinstances are cached per class and shared for the whole JVM, andsurefire reuses forks by default. A test that pins a shared logger's level to capture its output,
and restores only the appender in
finally, leaves that level pinned for every test that runsafter it — in the same test class, or in a different class sharing the same fork.
What changed
CapturedLog(the private helper merged in PR #527 for fleetd #525) out ofSessionManagerTestinto a shared test-scope class:dev.ltms.fleet.testing.CapturedLog.Behaviour is unchanged for the three original entry points:
at(Class, Level)captures the oldlevel and pins the new one,
of(Class)attaches without changing the level,close()detachesthe appender and restores the captured level.
CapturedLog, both needed by real call sites inthis sweep, neither changing what the three original methods do:
at(String, Level)/of(String)—AuditLoglogs through a named"audit"logger(
LoggerFactory.getLogger("audit")), not a class.at(Class, Level)would have captured thewrong
Loggerinstance (a different name resolves to a different cached logger).setLevel(Level)— lets a fixture that already pinned a coarser baseline (e.g.GitWorktreesTest's@BeforeEachpinning WARN) re-pin further for one test (to INFO) withoutchanging what
close()restores — always the level captured at construction, never anintermediate value.
setLevelpins across the 9 files the ticket named, plusSessionManagerTestitself (whose ownCapturedLogmoved out), to the shared helper:FleetdAwaitHerdrTest(1),FleetdReplyInboxSelectionTest(1),AuditLogTest(1),CompletionResolverTest(1),InjectorTest(4),LeadRolloverTest(1),AmqpConnectionFailureLoggerTest(1),GitWorktreesTest(8),WorktreeSessionManagerTest(1).SessionManagerTest's two explicitLevel.INFOpins, and its@BeforeAllDEBUGbaseline (pinSessionManagerLoggerToAKnownBaseline)— I did not touch either.
WorktreeSessionManagerTest(see below).Acceptance criteria — reported as run
1.
mvn -f fleetd/pom.xml clean installRan unpiped, redirected to a file,
echo $?on its own line:Verbatim summary line and result from that log:
(1701 = the pre-existing 1700 plus the one new proving test added below.)
2. Survey re-run — 0 files
I did not trust the ticket's table and re-derived my own survey before starting:
grep -rn "setLevel(" src/test/javafound 55 call sites; I classified each by hand as "restored" (acaptured-variable restore, or already the intentional
SessionManagerTestbaseline pair) or"unrestored literal pin" (a bare
Level.WARN/Level.INFO/Level.DEBUGargument with no restoreanywhere in the file). That classification produced exactly the 9 files fixed here — matching the
ticket's table by coincidence of measurement, not by trusting it.
Completion re-run, same methodology, automated as a small script (source shown for
reproducibility — classifies a file as leaking only if it has a literal
setLevel(Level.X)pin,no restore-to-a-captured-variable
setLevel(<ident>)anywhere in the file, and does not useCapturedLog):3. One proving test, ordered
Added to
WorktreeSessionManagerTest:@TestMethodOrder(MethodOrderer.OrderAnnotation.class)on the class.@Order(1)on the existingreleasePreservesDirtyWorktreeAndLogsWarn(the dirty-worktreerelease test — it already pins
SessionManager.class's logger to WARN viaCapturedLog).@BeforeAll/@AfterAllpair that captures this class's own true starting level forSessionManager.class's logger and pins a distinctive baseline (TRACE) before any test runs —mirroring
SessionManagerTest's own pattern, so "restored" can be told apart from "happened toalready read WARN".
@Order(2)test,sharedSessionManagerLoggerLevelIsRestoredAfterDirtyWorktreeReleasePinsWarn,asserting the logger's level is back to
TRACEright after@Order(1)runs.Ordering forced by: JUnit 5's
@TestMethodOrder(MethodOrderer.OrderAnnotation.class), whichguarantees
@Order(1)runs before@Order(2), and gives every unannotated method in the class thelowest priority (so they run after both, in whatever relative order they already ran in) — the
identical mechanism
SessionManagerTestalready uses for its own #525 proving test.This proves the within-class case only. JUnit 5 does not guarantee cross-class ordering by
default, and surefire's default class order is not something a single test can force. The
cross-class leak fleetd #525 actually measured —
WorktreeSessionManagerTest's dirty-worktree testpinning WARN and bleeding into a later-running
SessionManagerTestin the same fork — is fixed bythe same
CapturedLogmechanism this proving test exercises, but I did not write a test thatasserts the cross-class case itself, and I am stating plainly that it stays unproven by
construction, not dressing it up as proven.
Full-file run after adding the test (control, before any mutation):
4. Two mutations, both expected red
Mutation (a): remove the level restore from
CapturedLog.close().Before mutating,
shasum -a 256of the pristine file:486d6f5b5a30dc5ef7f75e5e10be353e720fb0de503825e88e8d96e30a61a2f7Change:
close()body reduced to onlylogger.detachAppender(appender);(thesetLevel(originalLevel)line removed).
Proof the mutation was actually applied — two greps with different search strings, each with a
control against the pristine copy, plus a
grep -nre-read:Test run with the mutation applied — red, assertion and exit code:
Restored the file from the pristine copy and confirmed byte-identical with
shasum -a 256(both files hashed to the same
486d6f5b...a1a2f7), then re-ran the control:Mutation (a) killed. It survived nothing, so no extra harness-proof cell is needed for it.
Mutation (b): put back the bare
detachAppender-onlyfinallyinWorktreeSessionManagerTest'sreleasePreservesDirtyWorktreeAndLogsWarn.Before mutating,
shasum -a 256of the pristine file:a722a98d828c82e00415d2a924d341e177ded704262aaa5963ea2d09a683df94Change: replaced the
try (CapturedLog log = CapturedLog.at(SessionManager.class, Level.WARN)) { ... }block with the original raw
LoggerContext/ListAppender/addAppender/setLevel(WARN)+try { ... } finally { sessionLog.detachAppender(appender); }shape (no level restore).Proof of application — two different-string greps, each with a control, plus a
grep -nre-read:Test run with the mutation applied — red, assertion and exit code:
Restored from the pristine copy, confirmed byte-identical with
shasum -a 256(both hashed toa722a98d...9a683df94), then re-ran the control:Mutation (b) killed. It also survived nothing, so no extra harness-proof cell is needed for it.
5/6. Mutation-application proof and survival handling
Covered inline above for each mutation: two greps with different search strings, each with a
pristine control, plus a
grep -nre-read confirming the actual line content. Both mutants werekilled by the proving test, so per the ticket's own rule ("a killed mutation needs no extra
harness-proof cell"), neither needed further proof of what a survival would have meant — neither
survived.
Item 4 — other unrestored shared static state (reported, not fixed)
fleetd/src/test/java/dev/ltms/fleet/FleetdLeadMailboxSelectionTest.java:55-59—captureFleetdLogs()attaches a freshListAppenderto the sharedFleetd.classlogger andreturns it, but the file never calls
detachAppenderanywhere (I counted 0 in this file). It iscalled from three tests (lines 70, 117, 131), so up to three
ListAppenders stay attached toFleetd.class's logger for the rest of the JVM fork's life. This is outside the 9-file scopenamed in this ticket, so I did not fix it — I only counted
addAppender/detachAppendercallsproject-wide (46 vs 45) to find this one file with the mismatch, and did not investigate further
whether it causes an observable test failure anywhere.
I did not do an exhaustive sweep for every possible kind of shared-static-state leak (only this
appender-specific check plus a quick look at
System.setPropertyusage, which was allpaired/restored, and
Thread.currentThread().interrupt()usage, which is the correct restore idiomafter a caught
InterruptedExceptioneverywhere I checked exceptFleetdAwaitHerdrTest, whichalready documents and handles its one deliberate case) — this is what I found within the scope of
this ticket, not a claim that it is the only such issue in the tree.
Hard constraints
.claude.json; nothing in this change touches that fixture pattern.GITEA_HOST/GITEA_TOKENpresence check in my worktree, reported as booleans only).CapturedLog.java); never usedgit add -A. Did not touchscripts/,.mcp.json,wiki/, orfleetd.yaml.mvndirectly via Bash; I have no IDE MCP tooling as a worker, somvnoutput above is thefull verification I have.
Files changed
fleetd/src/test/java/dev/ltms/fleet/testing/CapturedLog.java(new)fleetd/src/test/java/dev/ltms/fleet/FleetdAwaitHerdrTest.javafleetd/src/test/java/dev/ltms/fleet/FleetdReplyInboxSelectionTest.javafleetd/src/test/java/dev/ltms/fleet/auth/AuditLogTest.javafleetd/src/test/java/dev/ltms/fleet/inject/CompletionResolverTest.javafleetd/src/test/java/dev/ltms/fleet/inject/InjectorTest.javafleetd/src/test/java/dev/ltms/fleet/lead/LeadRolloverTest.javafleetd/src/test/java/dev/ltms/fleet/msg/AmqpConnectionFailureLoggerTest.javafleetd/src/test/java/dev/ltms/fleet/session/GitWorktreesTest.javafleetd/src/test/java/dev/ltms/fleet/session/SessionManagerTest.javafleetd/src/test/java/dev/ltms/fleet/session/WorktreeSessionManagerTest.javaCaveat for review
The cross-class ordering case (the exact interleaving fleetd #525 measured —
WorktreeSessionManagerTestrunning before
SessionManagerTestin one fork) is fixed by construction (both now use the samerestoring
CapturedLog), but it is not covered by an ordered, deterministic test — only thewithin-class case is. If a reviewer wants that cross-class case proven too, it would need something
like a JUnit test-suite class ordering configuration, which I did not add since it goes beyond a
single test file's scope and the ticket explicitly allows stating this as unproven.