Skip to content

test(relay): telemetry trace_context_lookup test flaky under parallel suite — reproduces on clean main #3929

Description

@tlongwell-block

Summary

telemetry::tests::trace_context_lookup_does_not_enable_callsites fails intermittently under the parallel buzz-relay lib suite. It passes 100% of the time when run filtered/standalone. Pre-existing on unmodified main — not introduced by any open PR.

Same class as #2458 (mesh_demo echo test), and worth filing separately because it has a different mechanism: this one is global-state interaction, not a timeout.

Failure

thread 'telemetry::tests::trace_context_lookup_does_not_enable_callsites' panicked at
crates/buzz-relay/src/telemetry.rs:489:13:
assertion failed: !tracing::enabled!(target: "trace_context_lookup_filter_test",
        tracing::Level::ERROR)

The test installs a TraceContextLookup layer with LevelFilter::OFF via with_default (a thread-local subscriber) and asserts no callsite is enabled. The failing assertion is that the filter did not suppress the callsite.

Reproduction

Unmodified main at 61ba9dfaa00852925058d1a024322fa53663a5bc, cargo test -p buzz-relay --lib, six consecutive runs:

run telemetry test
1 pass
2 pass
3 FAIL
4 pass
5 pass
6 pass

1/6 on clean main. Filtered to telemetry:: only, 6/6 pass — so it needs the rest of the suite running alongside it.

Also observed 2/6 on the #3844 branch head 6c8990b5fa200ef0369e520a3a5c0f880c9e3971, which is what prompted the check. That diff touches state.rs / api/mod.rs / invites.rs and nothing telemetry-related; the clean-main reproduction above is the negative control.

Likely mechanism (not confirmed)

tracing callsite interest is cached globally per callsite, not per-subscriber. Once any other test in the process registers a global default dispatcher, or a callsite's interest is cached as always while a different subscriber is active, a thread-local with_default filter can be bypassed — tracing::enabled! consults cached interest that outlived the other test's subscriber. Because rebuild/re-registration order varies with parallel scheduling, whether the poison lands before or after this test is a race.

Note telemetry.rs already has an ENV_LOCK mutex used by neighboring tests (test_service_resource_default_when_env_unset, :498) to serialize global-state mutation. This test does not take that lock. That's suggestive, but I have not proven the interfering test, so treat the mechanism as a hypothesis and the reproduction as the fact.

Impact

No CI impact today. cargo test -p buzz-relay --lib runs in no CI job — just test-unit (justfile:275-296) covers buzz-core/auth/cli/db/conformance/push-gateway, and the two nextest run invocations in ci.yml are narrowly filtered (:689-692 invite-security, :701-704 event-reminder). So this only bites locally and in pre-push hooks.

That's the real cost: it trains reviewers to wave off red suites. Two unfiled flakes in the same package is enough noise that a genuine regression can hide behind "probably the usual flake" — which is precisely the reasoning that lets a real failure through.

Suggested fix directions

  1. Have the test take the existing ENV_LOCK (or a dedicated dispatcher lock) so it cannot run concurrently with tests that install global dispatchers.
  2. Or use a unique, per-run callsite target so no other test can have poisoned its cached interest.
  3. Or move it to a tests/ integration binary where it gets its own process.

I'd take (2) if it works — it removes the shared state instead of serializing around it — but I haven't confirmed which test is the interferer, so (1) is the safer mechanical fix.

Found while reviewing #3844. Filing at @eva's and Tyler's request; not gating that PR.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions