~ knotless Search/
↑↓ move↵ open⇧↵ all results

grain.social/grain

photography-focused photo sharing platform

grain.social
1 collaborator
0
2

Telemetry's tests keep what is logged through one global subscriber

Merged
Merged chadtmiller.com asked to merge into feature/rust from grain.social/grain:fix/telemetry-flake

What changes

telemetry::tests::logged no longer sets a subscriber for its thread with with_default. A global subscriber goes in once, interested in every level. It writes each line into a thread-local buffer when that thread is inside logged(), and drops the line otherwise. logged() also rebuilds tracing's interest cache before it runs f. No code outside the tests changes.

Why

grain (lib) telemetry::tests::outgoing_calls was retried and logged FLAKY by harness/cov.mjs on the import pull (head fe819be).

The cause is how tracing caches interest. Each callsite's interest is cached once for the whole process. When exactly one dispatcher is alive, tracing-core (Dispatchers::rebuilder, which sets has_just_one to len() <= 1) works out a new callsite's interest from the default dispatcher of whichever thread reaches it first. While outgoing_calls holds the only scoped subscriber, a test on another thread can reach the outgoing callsite in Call::done first. The tests for identity, oauth and xrpc all call telemetry::send with no subscriber. When that happens the callsite is cached as never, the DEBUG line is never made, and the test sees two calls instead of three.

With one global subscriber there is only one dispatcher, and every thread without a default of its own falls back to it. So a callsite's interest no longer depends on which thread reaches it first. The rebuild in logged() covers a callsite that was being registered at the moment the global went in.

How it was checked

I read the code and tracing-core 0.1.36's callsite.rs and dispatcher.rs. Nothing was run locally. The harness check runs the lib tests.

Shortcomings

knotless's crates/knotless/src/telemetry.rs has the same with_default helper, so it can flake the same way. This pull leaves it alone.

🤖 Generated with Claude Code

Approved

This changes only the test helper telemetry::tests::logged. It installs one global subscriber at trace level, once. A thread-local buffer keeps the lines for the thread that is inside logged(), and other threads' lines are dropped. logged() also rebuilds the interest cache before it runs f.

The change looks correct. I checked these points:

  • With only one dispatcher, a callsite's cached interest no longer depends on which thread reaches it first. That is the cause the pull gives for the outgoing_calls flake.
  • Arc and Mutex are still used by answering in the same module, so the imports stay valid.
  • No other set_global_default or with_default call exists in crates, so nothing conflicts with the global install.
  • Because the buffer is thread-local, events logged on other threads are not captured. The old with_default had the same limit, so this is no regression.

The author says nothing was run, so I haven't seen the flake go away. A few repeated runs of the lib tests would show whether it did. That doesn't block the merge.

Merged as 3f01004
Part of a stack of 2
  1. Telemetry's tests keep what is logged through one global subscriber Landed as 3f01004
  2. main