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

CapturedLog.close() detaches the appender and no test proves it — the fix for #525/#529/#535 is itself unpinned #537

New Issue
Closed
opened 2026-09-12 08:25:35 +02:00 by ltms · 1 comment
ltms commented 2026-09-12 08:25:35 +02:00
Owner
Copy Link
Copy Source

Found while verifying #536 (fleetd #535). Measured on the merged tree.

The gap

CapturedLog.close() does two things:

@Override
public void close() {
    logger.detachAppender(appender);
    logger.setLevel(originalLevel);
}

Only the second line is pinned by a test. WorktreeSessionManagerTest.sharedSessionManagerLoggerLevelIsRestoredAfterDirtyWorktreeReleasePinsWarn (added in #533) proves the level is restored. Nothing proves the appender is detached.

Measured: I deleted logger.detachAppender(appender); and ran the full suite.

mvn clean install
exit=0
[INFO] Tests run: 1701, Failures: 0, Errors: 0, Skipped: 0
[INFO] BUILD SUCCESS

Zero [ERROR] lines. The mutant survives. The worker on #535 measured the same thing independently, on its own worktree, before I did.

Proof the mutation landed, against a pristine control read with git show HEAD:...: the literal line logger.detachAppender(appender); went 1 → 0, and total occurrences of the word detachAppender in the file went 2 → 1 (the remaining one is the javadoc). The close() body after mutation:

public void close() {
    logger.setLevel(originalLevel);
}

Restored afterwards; file back to e8deaa33c101b1bb99bb8211f03edc14829a584e29727aba5f8e301f06146b53, tree clean, green control re-run.

Harness proof, because a surviving mutant needs one before anyone reads meaning into the survival. I mutated the three call sites in FleetdLeadMailboxSelectionTest from CapturedLog.of(Fleetd.class) to CapturedLog.of(String.class) and ran that class:

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>

So the harness runs and can go red. The detach survival is real, not a harness that never executed.

Why this matters

CapturedLog exists because of fleetd #525: a test left a shared instrument mis-set for every test after it. The helper's whole job is to make that impossible. The detach half is the part that stops appenders accumulating on a JVM-wide cached logger across a reused surefire fork.

So the measuring apparatus for the leak family is itself unmeasured. Anyone editing close() — reordering it, wrapping it in a condition, or deleting the line while chasing something else — gets a fully green 1701-test build. That is the same shape as the defect the helper was written to prevent, one level up.

This is not urgent: nothing is broken today, and the harm from the original leak was bounded (unbounded list growth, no corrupted assertion — see #536's PR body). It is worth fixing because the cost is one small test and the thing being protected is now used in a growing number of files.

The fix

Add a test in a new CapturedLogTest that pins both halves of close(), so neither can be deleted silently:

  1. Appender detached. Open a CapturedLog on a throwaway logger, close it, then log one event through that logger, and assert the captured list did not grow. Alternatively assert logger.iteratorForAppenders() no longer yields the instance. Prefer the observable-behaviour form.
  2. Level restored. Already covered for the cross-test case, but pin it here too so the helper's own contract is readable in one place.
  3. setLevel(Level) does not change what close() restores. The javadoc claims this explicitly and no test checks it. Open with at(X.class, WARN), call setLevel(TRACE), close, assert the level is back to what it was before at — not WARN and not TRACE.

Use a logger name that no production class uses, so the test cannot itself become a cross-test leak.

Acceptance

  • mvn clean install passes, and the test count rises by the number of tests added.
  • For each new test: apply a mutation that should break it, show the suite going red with that test's own message, restore, confirm byte-identical with shasum -a 256, and run a green control.
  • The mutation for item 1 is exactly the one above: delete logger.detachAppender(appender); from close(). It must go red after this change. That is the acceptance criterion this ticket exists for.
  • Do not change CapturedLog's behaviour. This is a test-only change.
Found while verifying #536 (fleetd #535). Measured on the merged tree. ## The gap `CapturedLog.close()` does two things: ```java @Override public void close() { logger.detachAppender(appender); logger.setLevel(originalLevel); } ``` **Only the second line is pinned by a test.** `WorktreeSessionManagerTest.sharedSessionManagerLoggerLevelIsRestoredAfterDirtyWorktreeReleasePinsWarn` (added in #533) proves the level is restored. Nothing proves the appender is detached. Measured: I deleted `logger.detachAppender(appender);` and ran the full suite. ``` mvn clean install exit=0 [INFO] Tests run: 1701, Failures: 0, Errors: 0, Skipped: 0 [INFO] BUILD SUCCESS ``` Zero `[ERROR]` lines. The mutant survives. The worker on #535 measured the same thing independently, on its own worktree, before I did. Proof the mutation landed, against a pristine control read with `git show HEAD:...`: the literal line `logger.detachAppender(appender);` went 1 → 0, and total occurrences of the word `detachAppender` in the file went 2 → 1 (the remaining one is the javadoc). The `close()` body after mutation: ```java public void close() { logger.setLevel(originalLevel); } ``` Restored afterwards; file back to `e8deaa33c101b1bb99bb8211f03edc14829a584e29727aba5f8e301f06146b53`, tree clean, green control re-run. **Harness proof, because a surviving mutant needs one before anyone reads meaning into the survival.** I mutated the three call sites in `FleetdLeadMailboxSelectionTest` from `CapturedLog.of(Fleetd.class)` to `CapturedLog.of(String.class)` and ran that class: ``` 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> ``` So the harness runs and can go red. The detach survival is real, not a harness that never executed. ## Why this matters `CapturedLog` exists because of fleetd #525: a test left a shared instrument mis-set for every test after it. The helper's whole job is to make that impossible. The detach half is the part that stops appenders accumulating on a JVM-wide cached logger across a reused surefire fork. So the measuring apparatus for the leak family is itself unmeasured. Anyone editing `close()` — reordering it, wrapping it in a condition, or deleting the line while chasing something else — gets a fully green 1701-test build. That is the same shape as the defect the helper was written to prevent, one level up. This is not urgent: nothing is broken today, and the harm from the original leak was bounded (unbounded list growth, no corrupted assertion — see #536's PR body). It is worth fixing because the cost is one small test and the thing being protected is now used in a growing number of files. ## The fix Add a test in a new `CapturedLogTest` that pins **both** halves of `close()`, so neither can be deleted silently: 1. **Appender detached.** Open a `CapturedLog` on a throwaway logger, close it, then log one event through that logger, and assert the captured list did not grow. Alternatively assert `logger.iteratorForAppenders()` no longer yields the instance. Prefer the observable-behaviour form. 2. **Level restored.** Already covered for the cross-test case, but pin it here too so the helper's own contract is readable in one place. 3. **`setLevel(Level)` does not change what `close()` restores.** The javadoc claims this explicitly and no test checks it. Open with `at(X.class, WARN)`, call `setLevel(TRACE)`, close, assert the level is back to what it was before `at` — not `WARN` and not `TRACE`. Use a logger name that no production class uses, so the test cannot itself become a cross-test leak. ## Acceptance - `mvn clean install` passes, and the test count rises by the number of tests added. - For **each** new test: apply a mutation that should break it, show the suite going red with that test's own message, restore, confirm byte-identical with `shasum -a 256`, and run a green control. - The mutation for item 1 is exactly the one above: delete `logger.detachAppender(appender);` from `close()`. It must go red after this change. That is the acceptance criterion this ticket exists for. - Do not change `CapturedLog`'s behaviour. This is a test-only change.
ltms commented 2026-09-12 08:42:40 +02:00
Author
Owner
Copy Link
Copy Source

Fixed in #540, merged.

The acceptance criterion this ticket existed for

Deleting logger.detachAppender(appender); from CapturedLog.close() now fails. On f1640f5 that same mutation left a fully green 1701-test build; on the merged tree:

mvn clean install
exit=1
[ERROR] Tests run: 1704, Failures: 1, Errors: 0, Skipped: 0
[ERROR] dev.ltms.fleet.testing.CapturedLogTest.closeDetachesTheAppenderSoALaterLogIsNotCaptured
org.opentest4j.AssertionFailedError: close() must detach the appender: an event logged after
close must not be captured, but the captured list grew from 1 to 2 ==> expected: <1> but was: <2>

Exactly one failure, no collateral. I ran the full suite rather than the single test class, so this is directly comparable with the run that previously went green — a single-class run would have been a weaker claim than the one this ticket makes.

Verified independently

  • Branch sat on main's HEAD with one commit (checked with git merge-base, not assumed), so the checkout is the merge result.
  • mvn clean install: exit 0, Tests run: 1704, Failures: 0, Errors: 0, Skipped: 0. 1701 → 1704, +3.
  • One new file, 96 lines. CapturedLog.java untouched — confirmed by a name-only diff, not by reading the report.
  • Proof cell run twice: pristine side via git show HEAD:<path> reported 1 occurrence, mutated working tree reported 0. The two runs disagree, so the cell measured the file rather than its own pattern.
  • Restored byte-identical to e8deaa33c101b1bb99bb8211f03edc14829a584e29727aba5f8e301f06146b53, git status clean, green control at 1704/0/0/0.
  • CI run 1792: success.

Three design choices worth keeping

  1. Every test uses a unique logger name under capturedlog-test-only., which no production class uses. So the file that tests the leak family cannot join it — and CapturedLog's own re-measure commands never have to start naming this class as an exception.
  2. Test 1 asserts observable behaviour — an event logged after close() is not captured — rather than inspecting logger.iteratorForAppenders(). That is the form a real leak actually breaks: a later test's ListAppender silently gaining events from code that has nothing to do with it.
  3. Test 3 discriminates three ways: DEBUG (before at), WARN (pinned by at), TRACE (set mid-capture). A two-way assertion could not tell "restored correctly" from "left at the pinned level", which is exactly the distinction the javadoc claims and nothing checked.

One honest report from the worker, worth recording

Test 3's contract could not be isolated by mutating the shared logger.setLevel(originalLevel); line, because tests 2 and 3 both depend on it and both go red together. Rather than claim an isolation it did not have, the worker used a different semantically real mutation — making originalLevel non-final and having setLevel() overwrite it, reproducing exactly the defect the field's finality guards against — and that mutation turned only test 3 red.

That is the right handling of a mutation that cannot be aimed precisely, and it was stated plainly rather than glossed. A worker that had quietly reported "test 3 goes red" would have been telling the truth about the wrong mutation.

What this closes, and what it does not

Closed: all three halves of close()'s contract are now pinned, and the measuring apparatus for the #525/#529/#535 family is no longer itself unmeasured.

Not closed: the nine test files that still hand-roll the ListAppender + setLevel + finally detachAppender pattern. Every one pairs its pin with a restore, so none is a leak — they are unmigrated, not broken. They are named in CapturedLog's javadoc with two commands to re-measure them, and that paragraph says to delete itself once the first command comes back empty rather than to update a count.

Fixed in #540, merged. ## The acceptance criterion this ticket existed for Deleting `logger.detachAppender(appender);` from `CapturedLog.close()` **now fails.** On `f1640f5` that same mutation left a fully green 1701-test build; on the merged tree: ``` mvn clean install exit=1 [ERROR] Tests run: 1704, Failures: 1, Errors: 0, Skipped: 0 [ERROR] dev.ltms.fleet.testing.CapturedLogTest.closeDetachesTheAppenderSoALaterLogIsNotCaptured org.opentest4j.AssertionFailedError: close() must detach the appender: an event logged after close must not be captured, but the captured list grew from 1 to 2 ==> expected: <1> but was: <2> ``` Exactly one failure, no collateral. I ran the **full** suite rather than the single test class, so this is directly comparable with the run that previously went green — a single-class run would have been a weaker claim than the one this ticket makes. ## Verified independently - Branch sat on main's HEAD with one commit (checked with `git merge-base`, not assumed), so the checkout **is** the merge result. - `mvn clean install`: exit 0, `Tests run: 1704, Failures: 0, Errors: 0, Skipped: 0`. 1701 → 1704, +3. - One new file, 96 lines. `CapturedLog.java` untouched — confirmed by a name-only diff, not by reading the report. - Proof cell run **twice**: pristine side via `git show HEAD:<path>` reported 1 occurrence, mutated working tree reported 0. The two runs disagree, so the cell measured the file rather than its own pattern. - Restored byte-identical to `e8deaa33c101b1bb99bb8211f03edc14829a584e29727aba5f8e301f06146b53`, `git status` clean, green control at 1704/0/0/0. - CI run 1792: success. ## Three design choices worth keeping 1. **Every test uses a unique logger name under `capturedlog-test-only.`**, which no production class uses. So the file that tests the leak family cannot join it — and `CapturedLog`'s own re-measure commands never have to start naming this class as an exception. 2. **Test 1 asserts observable behaviour** — an event logged after `close()` is not captured — rather than inspecting `logger.iteratorForAppenders()`. That is the form a real leak actually breaks: a later test's `ListAppender` silently gaining events from code that has nothing to do with it. 3. **Test 3 discriminates three ways**: DEBUG (before `at`), WARN (pinned by `at`), TRACE (set mid-capture). A two-way assertion could not tell "restored correctly" from "left at the pinned level", which is exactly the distinction the javadoc claims and nothing checked. ## One honest report from the worker, worth recording Test 3's contract **could not be isolated** by mutating the shared `logger.setLevel(originalLevel);` line, because tests 2 and 3 both depend on it and both go red together. Rather than claim an isolation it did not have, the worker used a different semantically real mutation — making `originalLevel` non-final and having `setLevel()` overwrite it, reproducing exactly the defect the field's finality guards against — and that mutation turned **only** test 3 red. That is the right handling of a mutation that cannot be aimed precisely, and it was stated plainly rather than glossed. A worker that had quietly reported "test 3 goes red" would have been telling the truth about the wrong mutation. ## What this closes, and what it does not Closed: all three halves of `close()`'s contract are now pinned, and the measuring apparatus for the #525/#529/#535 family is no longer itself unmeasured. Not closed: the nine test files that still hand-roll the `ListAppender` + `setLevel` + `finally detachAppender` pattern. Every one pairs its pin with a restore, so none is a leak — they are unmigrated, not broken. They are named in `CapturedLog`'s javadoc with two commands to re-measure them, and that paragraph says to delete itself once the first command comes back empty rather than to update a count.
ltms closed this issue 2026-09-12 08:42:46 +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#537
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?