Flake (macOS once, ubuntu once): retention_loop's steady-state pass captured no INFO line on main (a_pass_with_nothing_to_evict_is_audible_and_not_an_alarm) — the scoped capture, not the loop

[emooreatx]

Seen once, on main's clippy + test (macos-latest) for 26ad854 (run 33939138651):

thread 'a_pass_with_nothing_to_evict_is_audible_and_not_an_alarm' panicked at tests/retention_loop.rs:303:5:
the pass emitted no INFO line, so a node whose retention loop has DIED looks exactly like one whose store is healthy. Silence is not a report.
test result: FAILED. 9 passed; 1 failed

The same test passed on the macOS lanes of e2f9557 (run 33931911725) and of #540 (run 33939306963, main + a one-line unit-test change). Never seen on ubuntu. The outcome assertions before it passed (WithinBounds, not a fault, no alarms) — only the "at least one INFO event was captured" half failed.

What the capture can and cannot see. tests/support/log_capture::capture runs the future under fut.with_subscriber(registry().with(CaptureLayer)). That scopes the subscriber to the instrumented future's own polls; an event emitted from a spawned task or a blocking thread (sqlx's pool workers, spawn_blocking) is invisible to it. run_pass emits its steady-state INFO inline after storage_summary() and evict_per_retention_policy(), so the expected line should be inside the scope — which is why this reads as a flake and not a deterministic miss. Worth checking on macOS specifically whether the INFO in the Within arm is reached on the path a fresh 3-trace store takes, or whether the pass returns through a branch that logs at DEBUG.

Ask: either make the capture thread-robust (tracing::subscriber::set_default guard for the duration, which also covers tasks spawned onto the current-thread test runtime) or make the assertion name the specific INFO it expects instead of "any INFO", so a miss says which line went quiet. Until then, a red macOS lane on main with only this test failing is this issue, not a regression — but it should not be allowed to become a permanent exemption.

Context: found while clearing main's lanes after the 0.5.197 merge (#529, #538, #539, #540).

🤖 Generated with Claude Code

https://claude.ai/code/session_01QVZ3v83uX8noLxXr7d7pu9

[emooreatx]

Second sighting, and on ubuntu this time (main, fa8fe03 = 0.5.199, run 34056535617, clippy + test (ubuntu-latest); macOS and Windows passed the same tree, and the PR lane had passed it minutes earlier):

a_pass_with_nothing_to_evict_is_audible_and_not_an_alarm  FAILED
panicked at tests/retention_loop.rs:303: the pass emitted no INFO line, so a node whose
retention loop has DIED looks exactly like one whose store is healthy. Silence is not a report.

So it is not a macOS clock/ordering quirk. Same assertion both times: run_pass returned WithinBounds, raised no alarm, and the scoped capture saw zero INFO lines from a pass that always logs one on success. A pass that ran and returned correctly but whose log line the capture did not see points at the CAPTURE, not the loop: a scoped tracing default is thread-local, so if the pass's INFO line is emitted from a thread the scope does not cover — spawn_blocking, a runtime worker other than the test's — or if another test in the same binary installs a global subscriber first, the line goes elsewhere and this assertion reads it as silence. Re-ran the failed jobs to get main green; the test's own words apply to the test: it cannot tell "the loop died" from "the line was emitted where I was not listening".

[emooreatx]

Third sighting (ubuntu, PR #561 run 34157383948, job 101851966623): a_pass_with_nothing_to_evict_is_audible_and_not_an_alarm — same shape, the scoped capture saw no INFO line while the other nine retention tests passed in the same binary. Passed on the previous three CI runs of the same code (#560) and in a local sequential sweep. Rerunning the job; this issue stays the place to fix the capture.

[emooreatx]

Root cause found and fixed in PR #565. It was never the retention loop: tracing-core caches a callsite's Interest process-wide, and when exactly one scoped dispatcher is alive (Dispatchers::has_just_one) it recomputes it from the registering thread's current default. A sibling test's tokio::spawned loop hits run_pass's callsites first on a worker thread under the global default and caches them never; the scoped with_subscriber capture is then never consulted, because the tracing::info! macro returns before asking. Reproduced locally at 1 in 4 with a probe event (the probe itself went missing on the failing thread; the sibling thread's probe was captured). The capture is now one process-global, always-interested layer routing to a tokio task-local sink: 12/12 retention runs, and the three other capture-using suites 3/3 each.

[emooreatx]

Merged as 7b06270. If the steady-state test ever reports empty again, the panic now reads NO EVENTS CAPTURED AT ALL — this is a capture failure, which is the signal to reopen this rather than #542's old reading of a missing INFO line.