test(testing_aids): deterministic in-process tracing capture

[sandersaares]

[Copilot speaking]

Makes tracing-emission test coverage and per-thread log capture deterministic in-process, eliminating cross-test pollution from tracing-core's process-global, permanent callsite-interest cache. Correctness no longer depends on the test runner's per-process isolation.

Problem

tracing-core caches, process-wide and permanently, whether each log callsite is "interested", deciding lazily the first time a callsite is reached. If the first thread to reach it has no subscriber, the callsite is cached as disabled forever - its field expressions never run again, from any thread. This causes non-deterministic capture failures and disappearing coverage of log statements, depending on test scheduling within a shared binary.

Approach

• A silent, always-interested global subscriber is installed before any test runs, via a #[ctor::ctor] process-init function calling testing_aids::tracing::initialize(). Because it is present from the first callsite hit and interested in every callsite, no callsite can be cached as disabled, so emission paths always run and stay covered. It produces no output on its own.
• Placement depends on binary kind: crate-root #[cfg(test)] #[ctor::ctor] for the crate's unit-test binary; an ungated file-level #[ctor::ctor] for each integration binary (cfg(test) is false there, so the crate-root init function never runs in them).
• The capture helpers assert that tracing was initialized and panic pointing to the guide if a binary's init function is missing; they never initialize lazily, which would be too late. A forgotten init function fails loudly and deterministically instead of causing a flaky miss.
• Text formatting is skipped when no output sink is active, so the always-interested subscriber keeps callsites enabled (fields materialize, coverage stays deterministic) without paying rendering cost while silent.
• testing_aids::tracing::write_to_stdout_and_buffer() provides a process-global capture bridge for asserting on events emitted from other threads in #[serial] integration tests, wired into cachet eviction tests. The returned guard exposes the captured lines (one entry per emitted line), with a non-detaching snapshot() for polling.
• Unit tests inspect tracing only through a thread-local Capture subscriber and never touch global state; cross-thread/global capture lives in #[serial] integration binaries.

Emitting telemetry through the observed package sidesteps all of this and is the recommended default. The rules for tests that must use tracing directly are documented in docs/tracing-tests.md, referenced from AGENTS.md.

[Copilot]

Pull request overview

This PR makes tracing-based test assertions deterministic across shared test binaries by ensuring tracing-core callsites cannot be permanently “interest-disabled” due to early emissions without a subscriber. It does so by installing a silent, always-interested fallback subscriber at process start (per test binary) and by providing a process-global capture bridge for cross-thread assertions in #[serial] integration tests.

Changes:

• Add testing_aids::initialize_logging() (silent fallback subscriber) + enforce “must be installed by ctor” via helper assertions.
• Introduce testing_aids::log_to_stdout_and_buffer() global capture guard for cross-thread/eventual assertions in serial integration tests.
• Update affected crates/tests/docs to follow the new tracing-testing model; remove tracing-test, add ctor + serial_test where needed.

Reviewed changes

Copilot reviewed 30 out of 31 changed files in this pull request and generated 3 comments.

Show a summary per file

File	Description
docs/tracing-tests.md	New repository guide describing the callsite-interest hazard and the required test patterns.
crates/testing_aids/tests/log_buffer.rs	New regression tests for the global stdout+buffer capture bridge.
crates/testing_aids/src/log.rs	Implements fallback subscriber init, asserts ctor installation, and adds global buffer capture guard.
crates/testing_aids/src/log_capture.rs	Ensures thread-local capture asserts fallback subscriber is already installed.
crates/testing_aids/Cargo.toml	Adds test-only deps needed by the new integration tests (ctor, serial_test).
crates/seatbelt/src/timeout/service.rs	Switches log-capture tests to testing_aids::LogCapture.
crates/seatbelt/src/testing.rs	Removes seatbelt-local LogCapture implementation (centralized in testing_aids).
crates/seatbelt/src/retry/service.rs	Switches log-capture tests to testing_aids::LogCapture.
crates/seatbelt/src/lib.rs	Adds crate-root #[cfg(test)] #[ctor::ctor] to install fallback subscriber for unit tests.
crates/seatbelt/src/hedging/telemetry.rs	Switches log-capture tests to testing_aids::LogCapture.
crates/seatbelt/src/hedging/service.rs	Switches log-capture tests to testing_aids::LogCapture.
crates/seatbelt/src/fallback/service.rs	Switches log-capture tests to testing_aids::LogCapture.
crates/seatbelt/src/chaos/latency/service.rs	Switches log-capture tests to testing_aids::LogCapture.
crates/seatbelt/src/chaos/injection/service.rs	Switches log-capture tests to testing_aids::LogCapture.
crates/seatbelt/src/breaker/service.rs	Switches log-capture tests to testing_aids::LogCapture.
crates/seatbelt/Cargo.toml	Adds dev-deps required for ctor init and shared testing helpers.
crates/fetch/src/lib.rs	Adds crate-root #[cfg(test)] #[ctor::ctor] fallback subscriber init for unit tests.
crates/fetch/Cargo.toml	Adds ctor dev-dependency for the new unit-test constructor.
crates/fetch_hyper/src/lib.rs	Adds crate-root #[cfg(test)] #[ctor::ctor] fallback subscriber init for unit tests.
crates/fetch_hyper/src/connection/tracked_stream.rs	Removes tracing_test::traced_test usage in unit tests.
crates/fetch_hyper/src/connection/client_connector.rs	Removes tracing_test::traced_test usage in unit tests.
crates/fetch_hyper/Cargo.toml	Adds ctor dev-dep and removes tracing-test dev-dep.
crates/cachet/tests/fallback.rs	Adds file-level ctor init so integration tests install the fallback subscriber.
crates/cachet/tests/eviction.rs	Migrates cross-thread eviction telemetry assertions to the global capture bridge + #[serial].
crates/cachet/tests/cache.rs	Adds file-level ctor init so integration tests install the fallback subscriber.
crates/cachet/src/lib.rs	Adds crate-root #[cfg(test)] #[ctor::ctor] fallback subscriber init for unit tests.
crates/cachet/Cargo.toml	Adds ctor + serial_test to support the new tracing test pattern.
Cargo.toml	Adds workspace deps for ctor and serial_test; removes tracing-test.
Cargo.lock	Locks new dependencies (ctor, serial_test) and removes tracing-test packages.
AGENTS.md	Links the new tracing testing guide and summarizes the enforced rules.
.spelling	Adds “callsite” to the dictionary.

---

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

[codecov]

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 100.0%. Comparing base (2cf0ffe) to head (44afd10).
⚠️ Report is 1 commits behind head on main.

Additional details and impacted files

@@           Coverage Diff           @@
##             main     #577   +/-   ##
=======================================
  Coverage   100.0%   100.0%           
=======================================
  Files         360      360           
  Lines       27886    27886           
=======================================
  Hits        27886    27886           

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

[Copilot]

Pull request overview

Copilot reviewed 38 out of 39 changed files in this pull request and generated 3 comments.

[Copilot]

Pull request overview

Copilot reviewed 38 out of 39 changed files in this pull request and generated 3 comments.

[Copilot]

Pull request overview

Copilot reviewed 38 out of 39 changed files in this pull request and generated 2 comments.

[Copilot]

Pull request overview

Copilot reviewed 38 out of 39 changed files in this pull request and generated 1 comment.

[Copilot]

Pull request overview

Copilot reviewed 38 out of 40 changed files in this pull request and generated 1 comment.

[Copilot]

Pull request overview

Copilot reviewed 38 out of 39 changed files in this pull request and generated no new comments.

Comments suppressed due to low confidence (1)

crates/testing_aids/src/tracing/capture.rs:69

• Capture::subscriber() builds a tracing_subscriber::fmt::layer() without disabling timestamps. The default formatter uses wall-clock time (via SystemTime::now()), which is both non-deterministic (hurts stable assertions) and can fail under Miri isolation (as already handled in the process-global sinks via .without_time()).

[Copilot]

Pull request overview

Copilot reviewed 38 out of 39 changed files in this pull request and generated 1 comment.

Comments suppressed due to low confidence (1)

crates/testing_aids/src/tracing/capture.rs:68

• Capture::subscriber() builds a tracing_subscriber::fmt::layer() without .without_time(). The rest of the test tracing infrastructure explicitly omits timestamps to keep captured output deterministic and to avoid SystemTime::now()/clock_gettime under Miri isolation; Capture should follow the same rule.

[Copilot]

Pull request overview

Copilot reviewed 38 out of 39 changed files in this pull request and generated no new comments.

Comments suppressed due to low confidence (1)

crates/testing_aids/src/tracing/capture.rs:69

• Capture::subscriber() uses tracing_subscriber::fmt::layer() without disabling timestamps. This makes captured output non-deterministic and can also trip Miri isolation (the fmt layer may read wall-clock time). The global sinks in output.rs already call .without_time() for these reasons; the thread-local capture should match that behavior.

[psandana]

[perf] SinkFilter::enabled runs on every tracing event process-wide (the InterestKeeper keeps all callsites enabled and callsite_enabled returns sometimes()). Both file_active() and buffer_active() acquire a process-global Mutex (LOG_FILE / LOG_BUFFER), so every info!/debug!/… on every thread now serializes on two global mutexes for the whole process lifetime — adding lock contention to every event and defeating parallel tracing in multi-threaded tests.

The stdout sink already avoids this by reading an AtomicBool (STDOUT_ENABLED). Suggest mirroring that: keep AtomicBool "active" flags for the file and buffer sinks, set them (Release) while holding the mutex when attaching/detaching the sink, and have file_active()/buffer_active() read the atomic (Acquire) instead of locking, keeping the hot per-event enabled path lock-free.

[psandana]

[design] Enforcement here (assert_initialized) only fires from the inspect helpers (write_to_stdout*, Capture::subscriber). A test binary that merely emits tracing and never calls a capture helper will never hit this assert, so a forgotten #[ctor::ctor] silently reintroduces the exact non-deterministic callsite-interest poisoning / coverage drift this PR exists to eliminate — with no loud failure, which is the failure mode the design explicitly promises to avoid.

The guard protects the case that already fails visibly (a missing capture) but not the subtle case (coverage drift) that motivated the work. Consider a CI lint requiring the init function in any test target that depends on tracing, or a #[test] shipped from testing_aids that asserts INITIALIZER.is_completed(), so emit-only binaries are covered too.

[psandana]

[design] The documented rule — if a binary uses write_to_stdout_and_buffer at all, EVERY test in that binary (not just the capturing ones) must be #[serial] — is a whole-binary invariant that nothing enforces. A future contributor adding an unrelated non-#[serial] test to the same file silently corrupts capture or trips the "buffer already active" panic in an unrelated test.

The PR already demonstrates the safer pattern (testing_aids/tests/log_buffer.rs and cachet/tests/eviction.rs put global-capture tests in their own dedicated binary). Recommend making "global-capture tests live in a dedicated integration binary" the stated rule, so the all-serial requirement stays local and trivially satisfied rather than a cross-cutting rule spread over an arbitrary binary.

[psandana]

[design] This identical #[ctor::ctor(unsafe)] fn init_test_tracing() { testing_aids::tracing::initialize(); } block is copy-pasted across every integration file and crate root (cachet/tests/*.rs, seatbelt/fetch/fetch_hyper lib.rs, testing_aids/tests/log_buffer.rs). Load-bearing copy-paste boilerplate is a drift/foot-gun risk (someone edits one copy, or omits it).

Since rlib static-init stripping genuinely forces per-binary registration, the ergonomic fix is to ship a declarative macro from testing_aids (e.g. testing_aids::init_tracing!()) that expands to the ctor with the correct attribute and unsafe token, so call sites become one line and the attribute/cfg details live in one place.

[psandana]

[guidelines] initialize() is a public function that can panic — ensure_initialized() calls try_init().expect(...), which fires if a test binary installs its own global subscriber before the ctor runs. Every other public fn in this module documents its panics (write_to_stdout, write_to_stdout_and_file, write_to_stdout_and_buffer all have # Panics), but initialize() does not — please add a # Panics section for consistency.

Also worth considering: because this runs inside a #[ctor] before main, that panic aborts process init with a confusing, hard-to-attribute failure. Treating an already-installed global as tolerable (ignore the AlreadyInit error) would let a misconfiguration surface as a normal per-test error instead of a ctor abort.

[psandana]

[doc-consistency] This # Panics section states snapshot() panics "if called after into_inner has consumed the guard." That condition is unreachable: into_inner(mut self) takes the guard by value, so once into_inner is called the guard is moved and a later snapshot() is a compile error, not a runtime panic — the .expect(...) inside snapshot() can never fire via that path. Documenting an impossible panic is misleading; keep only the real condition (poisoned mutex).

Suggested change

	/// Panics if the buffer mutex is poisoned, or if called after
	/// # Panics
	///
	/// Panics if the buffer mutex is poisoned.

[psandana]

[design/naming] Naming this module tracing collides with the ubiquitous tracing crate, which is why capture.rs must reference the real crate as ::tracing throughout and why call sites read awkwardly (testing_aids::tracing::Capture alongside tracing::info! in the same file). A non-colliding name (e.g. trace_capture or tracing_tests) would avoid the shadowing and the ::tracing disambiguation. Low-severity/naming, but cheap to fix now before the API is widely adopted across crates.