fleet/fleetd
3
0
Fork 0
Code Issues 73 Pull Requests Actions Packages Projects Releases 1 Wiki Activity

FleetdLeadMailboxSelectionTest leaks three ListAppenders onto the shared Fleetd logger, and the appender-balance invariant catches it #535

New Issue
Closed
opened 2026-09-12 07:59:46 +02:00 by ltms · 1 comment
ltms commented 2026-09-12 07:59:46 +02:00
Owner
Copy Link
Copy Source

Found by the fleetd #529 worker as its out-of-scope item 4, and verified here on main at bec87f9.

What is wrong

fleetd/src/test/java/dev/ltms/fleet/FleetdLeadMailboxSelectionTest.java:55-61:

private static ListAppender<ILoggingEvent> captureFleetdLogs() {
    Logger logger = (Logger) LoggerFactory.getLogger(Fleetd.class);
    ListAppender<ILoggingEvent> appender = new ListAppender<>();
    appender.start();
    logger.addAppender(appender);
    return appender;
}

Measured in that file:

addAppender:    1
detachAppender: 0
call sites of captureFleetdLogs(): 3   (:70, :117, :131)

So three appenders are attached to the Fleetd.class logger and none is ever removed. ch.qos.logback.classic.Logger instances are cached per class and shared for the whole JVM, and surefire reuses forks by default, so all three stay attached for every test that runs after this class in the same fork.

It also never calls appender.setContext(...), unlike every other capture site in the tree.

What the harm actually is, and what it is not

Being careful here, because this is not the fleetd #525 defect and should not be filed as if it were:

  • It does not pin a level, so it cannot corrupt another test's level-dependent assertions. That was #525/#529; this is a different leak.
  • It does not cross-contaminate assertions in the normal direction either. Each call creates a fresh appender, so a later test reading its own appender sees only its own events. I looked for that and could not construct it.

What it does do:

  1. Every Fleetd.class log event for the rest of the fork is appended to three lists that nobody reads and nothing bounds. That is unbounded growth across a long fork, proportional to how much the rest of the suite logs through that logger.
  2. Any future test that asserts on the Fleetd logger's appender set, or on a total event count rather than a filtered match, starts failing for a reason that has nothing to do with it — and the cause sits in a different file.
  3. It is the live template for the next instance. The helper reads as the house pattern, so the next person who needs to pin a level copies it and gets #525 back.

Severity is therefore lower than #529. It is hygiene with a measurable invariant, not a correctness bug I can demonstrate today.

The invariant is the useful part

Project-wide on bec87f9:

grep -rh 'addAppender'    fleetd/src/test/java --include='*.java' | wc -l   ->  47
grep -rh 'detachAppender' fleetd/src/test/java --include='*.java' | wc -l   ->  46

Off by exactly one, and the one localizes to this file. That difference is how the #529 worker found it without reading every capture site, which is worth more than this particular leak: a balance count over the whole test tree turns "is any appender leaked anywhere" into one command.

Note the count is a heuristic, not a proof — a file could attach twice and detach once and still balance globally against another file's surplus. Use it to find candidates, then read them.

Fix

Convert the three call sites to the shared dev.ltms.fleet.testing.CapturedLog helper added in #533, which restores both the appender and the level on close() and is used with try-with-resources. These sites do not need a level pin, so CapturedLog.of(Fleetd.class) is the right entry point. That also removes the missing-setContext difference for free.

Acceptance

  1. mvn -f fleetd/pom.xml clean install exit 0, with the Tests run / Failures / Errors / Skipped line quoted verbatim. No test count change is expected — this is a conversion, not new coverage.
  2. The balance count above re-run and reported: addAppender and detachAppender equal, with both numbers shown. If they are not equal, say so and name the remaining file rather than adjusting the claim.
  3. FleetdLeadMailboxSelectionTest shows 0 raw addAppender calls afterwards.
  4. One mutation, expected red: remove the detachAppender from CapturedLog.close() and show which test goes red. If nothing goes red, that is the finding to report — it would mean no test in the tree pins the appender half of the restore, only the level half, which #533's proving test covers. Do not write a sentence about what the survival means until the harness has been shown able to go red at all.
  5. Restore, show the file hash is byte-identical, and show the green control again.

Report the full hash of any file you restore, not an abbreviation.

Related: #529 (the level half of this family, fixed in #533), #525.

Found by the fleetd #529 worker as its out-of-scope item 4, and verified here on main at `bec87f9`. ## What is wrong `fleetd/src/test/java/dev/ltms/fleet/FleetdLeadMailboxSelectionTest.java:55-61`: ```java private static ListAppender<ILoggingEvent> captureFleetdLogs() { Logger logger = (Logger) LoggerFactory.getLogger(Fleetd.class); ListAppender<ILoggingEvent> appender = new ListAppender<>(); appender.start(); logger.addAppender(appender); return appender; } ``` Measured in that file: ``` addAppender: 1 detachAppender: 0 call sites of captureFleetdLogs(): 3 (:70, :117, :131) ``` So three appenders are attached to the `Fleetd.class` logger and none is ever removed. `ch.qos.logback.classic.Logger` instances are cached per class and shared for the whole JVM, and surefire reuses forks by default, so all three stay attached for every test that runs after this class in the same fork. It also never calls `appender.setContext(...)`, unlike every other capture site in the tree. ## What the harm actually is, and what it is not Being careful here, because this is **not** the fleetd #525 defect and should not be filed as if it were: - It does **not** pin a level, so it cannot corrupt another test's level-dependent assertions. That was #525/#529; this is a different leak. - It does **not** cross-contaminate assertions in the normal direction either. Each call creates a fresh appender, so a later test reading its own appender sees only its own events. I looked for that and could not construct it. What it does do: 1. Every `Fleetd.class` log event for the rest of the fork is appended to three lists that nobody reads and nothing bounds. That is unbounded growth across a long fork, proportional to how much the rest of the suite logs through that logger. 2. Any future test that asserts on the `Fleetd` logger's appender set, or on a total event count rather than a filtered match, starts failing for a reason that has nothing to do with it — and the cause sits in a different file. 3. It is the live template for the next instance. The helper reads as the house pattern, so the next person who needs to pin a level copies it and gets #525 back. Severity is therefore lower than #529. It is hygiene with a measurable invariant, not a correctness bug I can demonstrate today. ## The invariant is the useful part Project-wide on `bec87f9`: ``` grep -rh 'addAppender' fleetd/src/test/java --include='*.java' | wc -l -> 47 grep -rh 'detachAppender' fleetd/src/test/java --include='*.java' | wc -l -> 46 ``` Off by exactly one, and the one localizes to this file. That difference is how the #529 worker found it without reading every capture site, which is worth more than this particular leak: **a balance count over the whole test tree turns "is any appender leaked anywhere" into one command.** Note the count is a heuristic, not a proof — a file could attach twice and detach once and still balance globally against another file's surplus. Use it to find candidates, then read them. ## Fix Convert the three call sites to the shared `dev.ltms.fleet.testing.CapturedLog` helper added in #533, which restores both the appender and the level on `close()` and is used with try-with-resources. These sites do not need a level pin, so `CapturedLog.of(Fleetd.class)` is the right entry point. That also removes the missing-`setContext` difference for free. ## Acceptance 1. `mvn -f fleetd/pom.xml clean install` exit 0, with the `Tests run / Failures / Errors / Skipped` line quoted verbatim. No test count change is expected — this is a conversion, not new coverage. 2. The balance count above re-run and reported: `addAppender` and `detachAppender` equal, with both numbers shown. If they are not equal, say so and name the remaining file rather than adjusting the claim. 3. `FleetdLeadMailboxSelectionTest` shows 0 raw `addAppender` calls afterwards. 4. One mutation, expected red: remove the `detachAppender` from `CapturedLog.close()` and show which test goes red. If **nothing** goes red, that is the finding to report — it would mean no test in the tree pins the appender half of the restore, only the level half, which #533's proving test covers. Do not write a sentence about what the survival means until the harness has been shown able to go red at all. 5. Restore, show the file hash is byte-identical, and show the green control again. Report the full hash of any file you restore, not an abbreviation. Related: #529 (the level half of this family, fixed in #533), #525.
ltms commented 2026-09-12 08:26:27 +02:00
Author
Owner
Copy Link
Copy Source

Fixed in #536, merged.

Verified independently

The branch was based on main's HEAD 7d71194 with a single commit, so the checkout is the merge result — no separate merged-tree build was needed, and I checked that rather than assuming it (git merge-base returned main's HEAD exactly).

  • mvn clean install in a scratch worktree: exit 0, Tests run: 1701, Failures: 0, Errors: 0, Skipped: 0. Same total as main, which is what a conversion should do.
  • Appender balance, measured by me on both revisions rather than taken from the worker's report:
    • 7d71194: 47 addAppender / 46 detachAppender
    • c7903c1: 46 / 46
    • Control: the pattern matches 17 files on main, so 46 is a real count and not a broken-pattern zero.
  • Per-file balance on the branch: all 16 remaining files balanced 1:1 or n:n. FleetdLeadMailboxSelectionTest has dropped off the list entirely (0 addAppender). A global equality can hide two offsetting errors, which is why this was checked per file.
  • CI run 1789 on c7903c1: success.
  • CLAUDE.md / wiki block sync check: in sync: True.

What the conversion adds beyond the detach

The old helper never called appender.setContext(...). CapturedLog's constructor does, so the conversion fixes that too. It was not in this ticket's scope and is worth recording.

CapturedLog.of passes a null pinned level, so it does not change the logger's level on entry — the same behaviour the old helper had. close() still calls setLevel(originalLevel), which is a no-op here. No behaviour change for these three tests beyond the detach and the context.

The mutation survived, and that is now #537

Removing logger.detachAppender(appender); from CapturedLog.close() leaves the full suite green: exit 0, 1701/0/0/0, zero [ERROR] lines. The worker measured this first on its own worktree and reported it honestly instead of quietly moving on; I reproduced it. So the fix's central mechanism is unpinned. Filed as #537.

One vacuity found while proving the conversion is real

A surviving mutant means nothing until the harness is shown to work, so I ran my own harness proof aimed at this conversion's actual risk — that CapturedLog.of captures the wrong logger and the tests pass on empty output. I replaced CapturedLog.of(Fleetd.class) with CapturedLog.of(String.class) at all three sites:

exit=1
[ERROR] Tests run: 6, Failures: 2, Errors: 0, Skipped: 0
org.opentest4j.AssertionFailedError: say which key is missing:  ==> expected: <true> but was: <false>
org.opentest4j.AssertionFailedError: name the host that failed:  ==> expected: <true> but was: <false>

Two of the three went red. The third, noCoordinatorBlockLeavesTheFeatureOffSilently, stayed green — it asserts the WARN text is empty, so on its own it cannot tell "the feature warned nothing" from "I captured the wrong logger". That is the vacuous-test shape: it stays green when the behaviour it measures is absent.

It is covered in practice, because its two siblings in the same class prove of(Fleetd.class) captures live Fleetd output, and all three share the same call. Not worth a ticket on its own. Recording it because an empty-string assertion on captured output is a shape worth recognising on sight — it is always green when the instrument is broken. It predates this change rather than being introduced by it.

Restore

Each mutation was reverted and checked: CapturedLog.java back to e8deaa33c101b1bb99bb8211f03edc14829a584e29727aba5f8e301f06146b53, FleetdLeadMailboxSelectionTest.java byte-identical to HEAD, git status clean, green control re-run at 6/0/0/0.

Not closed by this

  • #537 — the detach half of CapturedLog.close() is still unpinned.
  • The nine test files that still hand-roll the ListAppender + setLevel + finally detachAppender pattern are unmigrated, not broken. Every one pairs its pin with a restore. They are named in CapturedLog's javadoc with two commands to re-measure them.
Fixed in #536, merged. ## Verified independently The branch was based on main's HEAD `7d71194` with a single commit, so the checkout **is** the merge result — no separate merged-tree build was needed, and I checked that rather than assuming it (`git merge-base` returned main's HEAD exactly). - `mvn clean install` in a scratch worktree: exit 0, `Tests run: 1701, Failures: 0, Errors: 0, Skipped: 0`. Same total as main, which is what a conversion should do. - Appender balance, measured by me on both revisions rather than taken from the worker's report: - `7d71194`: 47 `addAppender` / 46 `detachAppender` - `c7903c1`: 46 / 46 - Control: the pattern matches 17 files on main, so 46 is a real count and not a broken-pattern zero. - Per-file balance on the branch: all 16 remaining files balanced 1:1 or n:n. `FleetdLeadMailboxSelectionTest` has dropped off the list entirely (0 `addAppender`). A global equality can hide two offsetting errors, which is why this was checked per file. - CI run 1789 on `c7903c1`: success. - CLAUDE.md / wiki block sync check: `in sync: True`. ## What the conversion adds beyond the detach The old helper never called `appender.setContext(...)`. `CapturedLog`'s constructor does, so the conversion fixes that too. It was not in this ticket's scope and is worth recording. `CapturedLog.of` passes a null pinned level, so it does not change the logger's level on entry — the same behaviour the old helper had. `close()` still calls `setLevel(originalLevel)`, which is a no-op here. No behaviour change for these three tests beyond the detach and the context. ## The mutation survived, and that is now #537 Removing `logger.detachAppender(appender);` from `CapturedLog.close()` leaves the full suite green: exit 0, 1701/0/0/0, zero `[ERROR]` lines. The worker measured this first on its own worktree and reported it honestly instead of quietly moving on; I reproduced it. So the fix's central mechanism is unpinned. Filed as **#537**. ## One vacuity found while proving the conversion is real A surviving mutant means nothing until the harness is shown to work, so I ran my own harness proof aimed at this conversion's actual risk — that `CapturedLog.of` captures the wrong logger and the tests pass on empty output. I replaced `CapturedLog.of(Fleetd.class)` with `CapturedLog.of(String.class)` at all three sites: ``` exit=1 [ERROR] Tests run: 6, Failures: 2, Errors: 0, Skipped: 0 org.opentest4j.AssertionFailedError: say which key is missing: ==> expected: <true> but was: <false> org.opentest4j.AssertionFailedError: name the host that failed: ==> expected: <true> but was: <false> ``` Two of the three went red. **The third, `noCoordinatorBlockLeavesTheFeatureOffSilently`, stayed green** — it asserts the WARN text is empty, so on its own it cannot tell "the feature warned nothing" from "I captured the wrong logger". That is the vacuous-test shape: it stays green when the behaviour it measures is absent. It is covered in practice, because its two siblings in the same class prove `of(Fleetd.class)` captures live `Fleetd` output, and all three share the same call. Not worth a ticket on its own. Recording it because an empty-string assertion on captured output is a shape worth recognising on sight — it is always green when the instrument is broken. It predates this change rather than being introduced by it. ## Restore Each mutation was reverted and checked: `CapturedLog.java` back to `e8deaa33c101b1bb99bb8211f03edc14829a584e29727aba5f8e301f06146b53`, `FleetdLeadMailboxSelectionTest.java` byte-identical to HEAD, `git status` clean, green control re-run at 6/0/0/0. ## Not closed by this - **#537** — the detach half of `CapturedLog.close()` is still unpinned. - The nine test files that still hand-roll the `ListAppender` + `setLevel` + `finally detachAppender` pattern are unmigrated, not broken. Every one pairs its pin with a restore. They are named in `CapturedLog`'s javadoc with two commands to re-measure them.
ltms closed this issue 2026-09-12 08:26:33 +02:00
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
blocked
Cannot start until something else lands. The body says what.
 needs-live-proof
Merged and green, but never shown working on the running daemon. Not the same as done.
 ready-to-delegate
Scope, files and acceptance criteria are written. A worker can be briefed from the body alone.
 silent-default
A feature that compiles, passes tests, and ships turned off. Nine recurrences and counting.
No Label
Milestone
No items
No Milestone
Projects
Clear projects
No project
Assignees
Clear assignees
agent kevin ltms
No Assignees
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: fleet/fleetd#535
Delete Branch "%!s()"

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?