Tests pin shared logger levels and never restore them: 9 files, 19 pins, one proven cross-class collision — share SessionManagerTest's CapturedLog #529
Closed
opened 2026-09-12 07:27:43 +02:00 by ltms
·
1 comment
No Branch/Tag Specified
main
worker/fleetd-612-unita-87807e-1
worker/612-b3-mcpwirings-da2b58-3
worker/612-b2-cb185-176d3a-2
worker/612-b1-completion-457459-1
worker/612-agaps-73a926-2
worker/608-sleeps-3a64ff-3
worker/621-b4520b-1
worker/618-b83894-2
worker/fleetd-615-e05481-5
worker/lead-autocompact-5f1ab2-3
worker/fleetd-613-f85deb-3
worker/fleetd-608-flaky-nudge-test-d0c2d1-3
worker/lead-context-gauge-ad404f-1
worker/gauge-wiring-9158c1-4
worker/redeploy-slowstart-ead0e5-5
worker/charter-bytes-13668c-6
worker/rollover-outcome-291483-2
worker/589-f64303-2
worker/593-1a8025-5
worker/589-fcd2aa-1
worker/568-9fdaa2-3
worker/571-attempted-outcome-5739f7-2
worker/581-completionresolver-cas-sites-0542b7-6
worker/562-loop-health-wiring-test-99611c-5
worker/562-surface-loop-health-7df5cc-4
worker/575-waiter-cleanup-sites-62ad80-1
worker/572-answer-lock-release-46a9ae-5
worker/567-probe-channel-leak-a38fc5-6
worker/551-record-before-send-7cbf56-1
worker/561-listener-fanout-survives-a-throw-61d538-2
worker/555-redeploy-main-flow-seam-65c2f5-2
worker/556-injector-owns-registration-e027a5-1
worker/552-post-restart-mktemp-abort-bc2672-4
worker/553-onstatus-completion-leak-0da881-2
worker/550-shasum-linux-196132-1
worker/538-loop-dies-on-error-4a5eeb-6
worker/426-health-coverage-ef1fd4-4
worker/504-failed-reported-clean-3cfd66-3
worker/537-capturedlog-close-e4c437-2
worker/459-broken-link-targets-cadc17-5
worker/535-appender-leak-fe74c1-1
worker/512-part2-shutdown-detection-434701-9
worker/529-logger-level-sweep-2a5533-8
worker/528-drain-gate-call-site-5de83d-7
charter/forge-mcp-vs-token
worker/521-swap-guard-unpinned-28e931-5
worker/519-probe-test-harness-d25ab8-4
worker/525-logger-level-leak-1b4eb0-6
worker/518-fleetmcp-resolver-wiring-8ef96c-1
worker/512-drain-complete-line-7edd71-3
worker/517-abort-branch-and-jar-id-41b641-2
worker/500-9e52c9-3
worker/509-4912f4-2
worker/511-9a4b23-1
worker/493-479f45-2
worker/505-03f8b2-1
worker/492-followup-detect-unclear
worker/501-a31fa0-7
worker/498-451d1c-5
worker/494-1015ce-2
worker/492-209647-1
worker/489-001902-2
worker/480-relative-handover-path-906323-1
worker/480-b-handover-skill-45bf1f-5
worker/474-followup-source-pin-f54a55-17
worker/474-charter-check-on-reload-f54a55-17
worker/466-quarantine-repeatcount-report
worker/393-opencode-skill-seeding-71854b-13
worker/469-canonical-tool-names-2a472a-16
worker/466-quarantine-escalation-5ae9c1-15
worker/446-hot-exhausted-pattern-0af580-6
worker/464-charter-tool-name-guard-a85635-12
worker/463-listfleet-default-fails-open-f1c76c-11
worker/458-invariant-5-by-purpose-862f9a-10
worker/439-coordinator-row-gate-bc032a-8
worker/449-herdr-protocol-576015-4
worker/450-abstract-spawn-599e1c-5
worker/437-ack-refuses-177d91-1
worker/444-placement-window-feb56a-2
worker/440-helddurable-derived-d462d7-13
worker/425-rework-placement-resolve-c58ba1-9
worker/421-lead-peek-held-msgs-cdbad2-10
worker/435-fixed-policy-cap-fe11de-12
worker/422-gate-state-observability-9e79d6-11
worker/431-memberregistry-live-readers-cdbad2-10
worker/424-architect-slot-hot-038b41-7
worker/422-model-gate-spawn-c29f48-6
worker/425-default-profile-live-f55534-8
worker/415-coverage-wording-2cbf9c-5
worker/416-3ad1da-1
worker/418-588283-3
worker/deterministic-stamp-race-409-3cb7b6-10
worker/armed-reads-live-config-404-ed931f-9
worker/reply-peer-refusal-391-5a34bd-7
worker/models-allowlist-aa9e9b-3
worker/ttl-stamp-race-399-f1122f-8
worker/scrub-receipt-400-316b3e-5
worker/exhaustion-detection-395-105105-6
worker/scrub-abort-394-316b3e-5
fix/scrub-uid-abort
worker/task-scrub-517574-2
worker/t386-clock-bd5b78-4
worker/t384-scrub-813790-5
worker/t381-cc-748314-2
worker/t373-336973-2
worker/t365-3920c5-3
worker/t358-6e989b-1
worker/t355-8b321c-1
worker/fleetd-369-hermetic-git-tests-e8b19a-3
worker/fleetd-368-stale-lead-binding-f5682e-2
worker/fleetd-360-deploy-units-0d3793-1
worker/359-dead-lead-tabs-f1253b-4
worker/362-worktree-skills-c03e51-3
worker/361-coord-visibility-655144-1
362-plugin-visibility-and-drift
worker/errscan-bed2ca-2
worker/amqp-log-identity-bed2ca-2
worker/withdefaults-guard-561704
worker/sleepguard-82076d-1
worker/fd334-9ee1b6-5
worker/fd348-f1ab27-4
worker/fd335-a71c35-1
worker/fd342-174a17-2
worker/fd345-490d0f-3
worker/fleetd-337-5ec7d4-21
worker/fleetd-341-af5a6b-24
worker/fleetd-339-5ca0a2-23
worker/fleetd-338-83a4a1-22
worker/fleetd-333-281f46-18
worker/fleetd-329-11bdbb-16
worker/fleetd-330-2770fb-17
worker/fix-326-50506e-15
worker/fix-324-3e9bbf-14
worker/fix-323-b8287d-13
worker/fix-316b-bd0860-11
worker/fix-318-76ca36-9
worker/fix-317-486aec-8
worker/fix-315-ce47c5-6
worker/fix-307-275890-6
worker/fix-308-b4f664-7
worker/fix-309-ec3939-8
worker/fix-310-7a3974-9
worker/fix-302-52ad0e-9
worker/fix-298-ce1acb-8
worker/fix-297-66bd11-7
worker/fix-296-104622-6
worker/fix-293-bare-closetab-eb22b5-3
worker/fix-280-gone-ask-lapse-bca98e-2
worker/fix-290-reapidle-guard-coverage-9b0dd1-1
worker/fix-285-trust-seed-8f3565-10
worker/fix-284-backend-error-seat-85912c-11
worker/fix-282-chained-ask-e6d0bb-8
worker/fix-283-teardown-leaks-f40dfa-9
worker/fix-281-pin-handler-actions-4921ac-7
worker/audit-rendezvous-lifecycle-d072ae-2
worker/audit-health-placement-1a2476-6
worker/audit-teardown-exits-e207a5-3
worker/audit-launcher-asymmetry-27e370-4
worker/audit-rest-authz-6ca53c-5
worker/investigate-275-abandon-asking-fdef52-8
worker/fix-274-worktree-leak-b0095d-7
worker/fix-273-exhausted-pattern-9665b5-6
worker/fleetd-267-model-check-bd8068-1
worker/fleetd-131-archunit-18b834-7
worker/fleetd-266-sshagent-rename-a014ff-6
worker/fleetd-184-uid-claim-8e1f31-4
worker/fleetd-184-warn-b381ee-10
worker/fleetd-184-docs-be1d12-9
worker/fleetd-257-9bf010-7
worker/fleetd-103-23a113-6
worker/fleetd-247-342356-5
worker/fleetd-116-04dea8-4
worker/fleetd-252-a830e0-3
worker/fleetd-111-7e8673-9
worker/fleetd-155c-f8ef4b-8
worker/fleetd-176-b928ca-3
worker/fleetd-249-7a7878-2
worker/cb248-composition-root-b-9acdf7-15
worker/cb148-envrc-default-fa6c82-12
worker/cb201-unit5-wiring-6c12e6-8
worker/cb241-fallback-echo-1175e9-11
worker/cb149-trust-dialog-2392a5-9
worker/cb134-148-overlay-visible-c9b986-10
worker/cb234-session-id-keyed-04e1fc-1
worker/cb201-unit3-nudge-abdf5c-6
worker/cb201-unit2-policy-c1102c-5
worker/cb201-unit4-outcome-a13bfa-7
worker/cb201-unit1-classifier-91b9b1-4
worker/cb201-227-refine-831980-3
worker/cb175-model-readback-0f085f-1
worker/cb222-charter-tmpdir-17f013-1
worker/cb226-architect-slot-race-cd3aa8-3
worker/cb224-worktree-root-group-024523-2
worker/cb-123-role-demotion-c600f7-2
worker/cb-219-opencode-roots-1f677e-1
worker/cb214-claude-session-id-b9eab4-4
worker/cb213-zdotdir-wrong-process-dd6de4-3
worker/cb211-exhaustion-classification-9546e0-2
worker/cb137-ambiguous-task-4df3d8-4
worker/cb209-agentsessionid-4dfdb6-2
worker/cb185-hostenvnames-2692b5-3
worker/cb206-opencode-sqlite-128718-2
worker/cb185-worktree-group-fc0c99-1
worker/cb-137-ask-ticket-e7760c-2
worker/cb-172-broker-uri-d36ae4-4
worker/cb-175-model-readback-76ead6-3
worker/cb-161-pane-ancestry-293510-1
worker/cb-164-rebase-885863-8
worker/cb-164-empty-scrape-false-success-1a80af-3
fix/cb-197-ticket-ttl-from-completion
worker/cb-189-remote-url-coverage-4692f3-1
worker/cb-185-blockers-027756-4
worker/cb-192-gap-log-11b631-2
worker/cb-633-fix-5f4396-3
worker/cb185-router-d6436d-3
worker/cb185-router-routing-gaps-9e9d33-3
worker/cb185-paneids-992586-2
worker/cb-633-allow-list-union-ed374b-1
worker/cb-157-credential-in-remote-url-496e44-2
worker/cb-641-health-herdr-evidence-8f1f54-6
worker/cb-640-health-msg-evidence-99c9cd-1
worker/cb-642-fleets-status-skill-bbbc40-5
cb-634-ide-mcp
worker/lead-comms-wiring-c014b9-7
worker/lead-mailbox-c19577-6
worker/autocompact-window-82bc2f-5
worker/cb-634-probe-18056f-4
worker/cb635-broker-urienv
worker/cb-632-config-retry-8e0efa-7
lead/cb-622e-claude-md
lead/cb-622-followup
worker/cb-622a-165dff-1
lead/cb-622d-opencode-mount
worker/cb-622b-717c67-2
worker/cb-622c-ab7759-3
worker/cb-617b2-20ca4b-3
worker/cb-617a-5c2f4a-1
worker/cb596-4e49ef-3
worker/cb586-10500c-1
worker/cb-606-b9343a-25
worker/cb604-1445f8-24
worker/cb582-477374-21
worker/cb584-8c2281-22
worker/cb600-e6b9a9-20
worker/cb602-ce257f-19
worker/cb601-b42837-18
worker/cb598-6c7ba7-17
worker/cb599-740fe4-16
worker/cb597-282224-15
worker/cb590fix-185e9a-10
worker/cb528-recovery-race
worker/cb594-96bead-8
worker/cb590-916766-2
worker/cb527-997d99-3
worker/cb592-env-leak-3cbf9c-1
worker/cb588-async-ticket-nudge-3218f7-5
worker/cb578b-9dcb13-6
worker/cb581-d24826-5
worker/m2-u5-ef8c42-15
worker/cb578a-516499-2
worker/cb576-01a04b-17
worker/cb579-lead-tab-acba06-20
worker/cb580-terminal-health-ed6058-21
worker/cb577-f36fdc-18
worker/cb573b-3db06f-16
worker/cb568c-f36fdc-18
worker/cb568-drop-cause-c3ac1c
worker/cb575-cancelled-notification-c3ac1c
worker/m4-sol-a2cbec-3
worker/cb574-async-ask-c3ac1c
worker/cb573-health-model-8ca857-14
worker/cb572-unknown-target-7f2e35-13
worker/u4-700706-9
worker/u3-b9fcb6-6
worker/u2-ef5b68-4
worker/u1-469dce-1-clean
worker/u1-469dce-1
worker/cb-564-health-events-70cf7e-2
worker/cb-565-recycle-drops-role-98e58f-3
worker/cb-563-missing-reply-df2866-1
worker/cb-562-readiness-gate-silent-6c23c9-3
worker/cb-560-architect-presence-da8155-1
worker/cb-561-architect-silent-off-a71cab-2
worker/cb-548-bind-architect-slot-fe1b8c-1
worker/parity-overlay-settings-5fb711-1
secrets-central-store
cb-559-hot-key-correction
cb-557-fleet-role-pools
worker/cb-553-maxload-explicit-spawn-305ee3-6
worker/cb-551-idle-lead-heartbeat-f1633c-1
worker/cb-544-drain-preserves-worktree-925fad-3
worker/cb-552-docs-sync-1cb9cf-4
worker/cb-548-rendezvous-guard-rebased
worker/cb-548-rendezvous-guard-116b53-10
worker/cb-548-authz-v2-586df6-8
worker/cb-548-authz-264363-5
salvage/cb-528b-codex-home
salvage/cb-528a-codex-launcher
CB-518-primary-flow
feature/peer-launcher-spi
cb-103-injector
v1.1.0
v1.0.0
Labels
Clear labels
blocked
needs-live-proof
ready-to-delegate
silent-default
Cannot start until something else lands. The body says what.
Merged and green, but never shown working on the running daemon. Not the same as done.
Scope, files and acceptance criteria are written. A worker can be briefed from the body alone.
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
Notifications
Due Date
No due date set.
Dependencies
No dependencies set.
Reference: fleet/fleetd#529
Reference in New Issue
Block a user
Blocking a user prevents them from interacting with repositories, such as opening or commenting on pull requests or issues. Learn more about blocking a user.
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?
Follow-up to #525 (merged, PR #527). #525 fixed one file. This is the rest of the repo, and it adds the one thing #525 could not: a measured cross-class collision rather than a suspected one.
All numbers below measured on
mainata6415f3.The shape
A test pins a shared logger's level to capture output:
ch.qos.logback.classic.Loggerinstances are cached per class and shared for the whole JVM, and surefire reuses forks. So the level stays pinned for every test that runs afterwards — in that class, and in any other class in the same fork.This is the sixth member of the vacuous-test family, defined by consequence (the suite stays green when the behaviour is absent): a test that leaves a shared instrument mis-set for every test after it. The test with the bug passes. The damage lands on a later test and looks like that test's bug.
The survey
Files where every
setLevelcall is an unrestored literal pin (a restore counts assetLevel(null)orsetLevel(<captured variable>)):dev/ltms/fleet/FleetdAwaitHerdrTest.javadev/ltms/fleet/FleetdReplyInboxSelectionTest.javadev/ltms/fleet/auth/AuditLogTest.javadev/ltms/fleet/inject/CompletionResolverTest.javadev/ltms/fleet/inject/InjectorTest.javadev/ltms/fleet/lead/LeadRolloverTest.javadev/ltms/fleet/msg/AmqpConnectionFailureLoggerTest.javadev/ltms/fleet/session/GitWorktreesTest.javadev/ltms/fleet/session/WorktreeSessionManagerTest.java9 files, 19 pins.
A number correction worth recording: an earlier, looser version of this survey said 15 files. That regex treated only
setLevel(null)as a restore and so missed restores made through a captured variable. 9 is the number I stand behind. The script that produces it is in this ticket's history — re-run it rather than trusting the table, since #525 already removedSessionManagerTestfrom this list and the next fix will remove another.The one proven collision
WorktreeSessionManagerTest.java:267-272pinsSessionManager's logger toLevel.WARNin afinallythat only callsdetachAppender. That is the same loggerSessionManagerTestuses.Measured while verifying #525, running both classes in one fork with
-Dsurefire.runOrder=reversealphabeticalsoWorktreeSessionManagerTestruns first, and withSessionManagerTest's@BeforeAllDEBUG baseline removed:The
WARNcomes fromWorktreeSessionManagerTest:272. Two of #512's drain assertions go vacuous under it — they assert an INFO line is present, and an INFO line cannot be emitted through a logger pinned at WARN, soassertTrueseesfalse.What currently prevents this is
SessionManagerTest's@BeforeAllDEBUG baseline, not anything inWorktreeSessionManagerTest. Nobody may remove that@BeforeAllas "only there for #525's proving test" — it is what keeps two other tests honest. I also measured the other half: removing #522's two per-testLevel.INFOpins while keeping the@BeforeAllpasses (24 + 72, 0 failures), so the per-test pin really is redundant and the baseline is the load-bearing part. PR #527's own comment has this backwards; #525's closing comment records the correction.A second collision pair — shape confirmed, collision NOT run
FleetdAwaitHerdrTest:201-210pinsFleetd.classtoDEBUGand only detaches.FleetdReplyInboxSelectionTest:54-64pins the sameFleetd.classlogger toINFOand only detaches.PR #527's survey described these as leaking "into each other". I checked, and that part is wrong: each file pins the level it needs at the start of its own capture, so each is immune to the other's leftover. The victim is a third party — any future test that asserts on
Fleetdlogging without pinning a level itself, which is exactly the trap #512 fell into. I have established the shape by reading both files; I have not run a collision for this pair, and I am not claiming one.GitWorktreesTestis a third variation worth its own line: its@BeforeEachre-pinsGitWorktrees.classtoWARNbefore every test, so it self-heals within the class, but 7 tests re-pinINFOmid-test (lines 815, 830, 1438, 1455, 1475, 1498, 1686) and the@AfterEachonly detaches. So the level this class leaves behind for the next class depends on which test happened to run last.Asked for
CapturedLogto a shared test helper. #525 added it as aprivate static final classinsideSessionManagerTest. Move it to a test-scope utility (suggestion:dev.ltms.fleet.testing.CapturedLog) unchanged in behaviour:at(Class, Level)captures the old level and pins the new one,of(Class)attaches without changing the level, andclose()detaches the appender and restores the captured level. try-with-resources then makes "restored one, forgot the other" unwritable, because there is one thing to close.Acceptance
mvn -f fleetd/pom.xml clean installexits 0. Quote theTests run / Failures / Errors / Skippedline verbatim. Do not pipe the command — a pipe hides a failure behind a zero exit. Redirect to a file andecho $?on its own line.WorktreeSessionManagerTest's dirty-worktree test has run,SessionManager's logger level is what it was before. Say how you forced the ordering, since cross-class ordering is not guaranteed by default — if you cannot make it deterministic, say so and assert within-class instead, and state plainly that the cross-class case is unproven.CapturedLog.close()and show the proving test go red, quoting the assertion and the exit code. (b) Separately, re-introduce the baredetachAppender-onlyfinallyinWorktreeSessionManagerTestand show the same. Prove each mutation applied with two greps using different search strings, each with a control against a pristine copy, then restore and confirm byte-identical withshasum -a 256, then a green control run.Related
CapturedLogcomes from.Fixed by #533, merged to main as
af95897. A javadoc follow-up went in as7f8a882.What I verified myself, in a scratch worktree at
8ea5c2bNot promoted from the worker's report — re-run here.
mvn -f fleetd/pom.xml clean installexit 0,Tests run: 1701, Failures: 0, Errors: 0, Skipped: 0, BUILD SUCCESS.logger.setLevel(originalLevel);fromCapturedLog.close()→ exit 1,Tests run: 25, Failures: 1, the one failure beingsharedSessionManagerLoggerLevelIsRestoredAfterDirtyWorktreeReleasePinsWarnwithexpected: <TRACE> but was: <WARN>. Restored byte-identical.ListAppender+setLevel+finally detachAppenderpattern inreleasePreservesDirtyWorktreeAndLogsWarn→ exit 1, one failure, the same assertion. Restored byte-identical.git diff --quietclean, full suite exit 0, 1701/0/0/0.Both mutants were killed, so neither needed a separate harness-proof cell — the kill is itself the proof the cell can go red. That economy came from the fleet01 lead and this ticket was the first to be written against it; it held up, and it saved two cells here.
Mutation (a) is the one that mattered most, and it is the reason this ticket existed. The instrument is now shared by ten files, so a silent regression in
CapturedLog.close()would have degraded every one of them at once while each file's own tests stayed green. Mutating the subsystem could never have found that; only mutating the instrument does. That distinction also came from the fleet01 lead.The survey, re-measured rather than taken from the report
On
a6415f3, nine files carried 19setLevelpins on a raw logbackLoggerwith no restoring call. On the branch that set is empty.One thing worth recording because it nearly read as a miss:
GitWorktreesTeststill shows sevensetLevelcalls afterwards. They arereportingLog.setLevel(...)on theCapturedLoginstance, whoseclose()restores the original, so they are re-pins through the helper's own method and not leaks. A survey that greps\.setLevel(without looking at the receiver reports this file as still broken. Mine did, at first.Three measurement errors of my own in this verification, all false zeros or false counts
Recording these because the ticket's whole subject is an instrument that lies:
for f in $filesloop over a newline-separated list returned nothing useful — the shell here is zsh, which does not word-split an unquoted parameter. The loop body simply never ran on the right values."$B:fleetd/..."lost its:f— zsh applied a history-style modifier to$B:f. The error surfaced as an "ambiguous argument" naming...-8eetd/, which is only readable once you know what to look for.git grep -hE '^\s*@Test'returned 0 across every revision.\sis not valid in git grep's POSIX ERE. A plausible-looking zero that was entirely an artefact of the pattern.All three are the zero-match family in my own hands, and the second and third produced numbers rather than errors, which is the dangerous form. The first
unrestoredcolumn I printed was also mislabelled: it counted pinning calls, not unrestored ones, so every correctly-paired file appeared to have one leak. That number was plausible, which is exactly why it needed re-deriving rather than reading.One number I had wrong and am retiring
I had been carrying
1699as main's test count. Measured now:a6415f3has 1695@Testplus 2 parameterized/repeated, and the branch has 1696 plus 2. The delta is exactly +1, matching the per-file count (WorktreeSessionManagerTest24 → 25). So the base is 1700, not 1699, and the worker's arithmetic was right where mine was wrong. No Java file differs betweena6415f3and main at8335b12, so the base is the same on both.The follow-up,
7f8a882The new helper's javadoc said it is "the one way to pin or capture a logger's level and output in this test tree". That is false: nine files still hand-roll the pattern, with 42 raw
setLevelcalls between them (FleetdStartupReportTest,GitHostShapeReportTest,MemberCredentialsGapReportTest,MemberTrustModelReportTest,FleetHealthMonitorTest,ClaudeCodeLauncherTest,HerdrPeerLauncherAllowListWiringTest,HerdrPeerLauncherCharterTest,OpenCodeLauncherTest).None of them is a defect — every one pairs its pin with a restore, so none is the #525 leak and none was in this ticket's scope, which was the unrestored pins only. The sentence was the problem, not the code: a reader who believes "the one way" and then greps finds nine counter-examples and cannot tell a leftover from a violation. Replaced with what is true, plus the two commands that re-measure it and an instruction to delete the paragraph once the first command comes back empty, rather than to keep a count current.
What this ticket did not close
Stated plainly rather than left to be assumed:
@TestMethodOrderorders methods inside one class; it does not order classes. The exact #525 interleaving —WorktreeSessionManagerTestpinning WARN and bleeding into a laterSessionManagerTestin the same fork — is fixed by the shared restoring helper, but no deterministic test asserts it. The worker flagged this itself rather than claiming more than it tested, and the javadoc on the proving test says so too.FleetdLeadMailboxSelectionTestattaches threeListAppenders to the sharedFleetdlogger and never detaches any. Filed as #535. Different family from this one — it pins no level, so it cannot corrupt a level assertion — and the genuinely useful part is the invariant that found it: a project-wideaddAppendervsdetachAppenderbalance count, 47 against 46, off by exactly one.Closing.