mirror of
https://github.com/block/buzz.git
synced 2026-10-30 14:01:37 +00:00
1f16f621d8
## Summary
A cold relay taking a burst of new connections spent most of its CPU on
two things that don't scale with useful work. This PR removes both.
**Log filtering held a contended lock.** `EnvFilter` (tracing-subscriber
0.3.23) takes a shared `RwLock` read on every span enter and exit, even
when no directive names a span. Every poll of an instrumented future
enters its span, and the relay installs two per-layer `EnvFilter`s (logs
and OTEL), so every worker contends on those locks. Plain `target=level`
directive lists now filter through
`tracing_subscriber::filter::Targets`, which keeps no per-span state.
Directives that name spans or fields still use `EnvFilter`, which is the
only filter that understands them.
**Each reader re-read the community's open channels.** A reader's
accessible channels are its member channels plus the community's listed
open channels, and the open half is the same for every reader. The
per-reader cache stored the union, so every miss fetched every open
channel row again. The lookup is now two cached halves:
- member channels, per reader, cached as before;
- open channels, once per community.
The shared half is used for a bounded time. Cross-pod invalidation is
best-effort, so a pod can miss the drop that follows a channel becoming
private, unlisted or deleted elsewhere. Each cached open set records
when its database read began, and readers use it only for
`OPEN_CHANNELS_MAX_AGE` (1 s) after that. After that the next reader
re-reads it. **Accepted trade-off:** if an invalidation is lost, any
reader on that pod can be granted a just-revoked open channel, history
included, for at most 1 s. That includes a reader with no cache entry,
which on `main` always read the database. This is a new exposure for
those readers. With no bound, the shared set could have served that
channel for its 10 s TTL. Readers with a cached entry already had a 10 s
window on `main`, so for them the bound is tighter than before. An exact
per-community version check would remove the window but needs a schema
change, so it's tracked as a follow-up.
Invalidations still drop the halves. A community-wide accessible-channel
or channel-deleted invalidation drops both halves, and a membership
invalidation drops only that reader's member half. The age bound counts
from the start of the read, so open-set fills need no fence: a fill that
raced a drop is still at most 1 s stale. Uncached callers of
`get_accessible_channel_ids` get the same set as before, now built from
the two halves. Open-set reads are counted by
`buzz_open_channels_cache_hits_total` and
`buzz_open_channels_cache_misses_total{reason="absent"|"expired"}`.
**Metric meaning change:** `buzz_accessible_channels_cache_hits_total`
and `buzz_accessible_channels_cache_misses_total` keep their names but
now count only the per-reader member half. Dashboards that read them as
whole-lookup hit rates should add the open-set counters above.
Empty levels (`target=`) stay on `EnvFilter`. `Targets` reads an empty
level as ERROR while `EnvFilter` reads it as TRACE, so only
`target=level` directives with a non-empty level take the `Targets`
path.
## Results
Measured with the relay load generator (#8636) on one Linux machine. The
relay ran as a release build on 8 pinned cores, with local Postgres,
Redis and MinIO; the generator ran on separate cores. The fixture is one
community with 2,000 open channels. Clients connect in a burst against a
cold relay: 48k WebSocket clients and 4.8k HTTP agents.
Each arm restored the same database snapshot and ran the same generator
binary and scenario. Arms were rotated (base/before/after, then
before/after/base, then after/base/before), and the table shows medians
of three runs per arm. Both columns after base also carry #8666, so the
comparison isolates this PR's design.
- **before** is this PR's first revision, which had an unbounded shared
open set.
- **after** is this head, where the open set is bounded to 1 s.
| | base | before | after |
|---|---|---|---|
| relay cores (mean) | 6.37 | 2.39 | 2.45 |
| connect p99 | 3,870 ms | 40 ms | 42 ms |
| subscribe EOSE p99 | 12,952 ms | 110 ms | 112 ms |
| history EOSE p99 | 1,252 ms | 68 ms | 72 ms |
| live delivery p99 | 26,421 ms | 54 ms | 55 ms |
| HTTP query p99 | 16,426 ms | 44 ms | 43 ms |
| DB tuples returned/s | 1.04M | 43k | 49k |
| DB transactions/s | 4,397 | 4,065 | 4,062 |
| relay RSS peak | 12.6 GB | 10.7 GB | 10.7 GB |
| errors | 16, plus 241k throttled | 0 | 0 |
The 1 s bound costs about 1,400 extra open-set reads per run, within
run-to-run noise of the unbounded version. One run in each of the two
right-hand arms had a slow tail (connect p99 0.8–1.3 s), which the
medians absorb.
An earlier revision bound the shared set to a per-reader digest instead.
That was exact, but in the same kind of A/B its per-miss digest query
returned about 28 times the tuples per second of the unbounded version.
It gave back the database savings, so this revision uses the time bound.
The open-channel gain scales with how many listed open channels a
community has. The filter gain doesn't depend on the fixture.
## Rollout
There's no flag, so the change takes effect on deploy. There's no schema
or data change, so reverting the commit is the rollback.
1. Deploy to staging and compare relay CPU and connect and EOSE p99
under a connection burst.
2. Watch `buzz_open_channels_cache_misses_total{reason="expired"}`.
Expect at most about one per second per active community per pod.
3. Confirm the deployed `RUST_LOG` and `BUZZ_OTEL_FILTER` are plain
`target=level` lists, so they take the `Targets` path. Other values fall
back to `EnvFilter` and keep today's cost.
## What got simpler
- `invalidate_channel_deleted_local` now reuses the community-scoped
accessible-channel drop instead of repeating it.
- Tests seed accessible channels through one `seed_accessible_channels`
helper instead of writing cache internals.
## Tests
- `telemetry::tests::only_plain_target_level_directives_use_targets`
checks which directive strings are plain. It covers span directives,
field directives, whitespace, empty segments, empty targets (`=debug`)
and bad levels.
- The rewritten `env_filter_tests` assert on captured log output rather
than `Display` strings or cached callsite interest, so they are stable
when run in parallel. `span_directives_keep_env_filter_semantics` proves
that `[conn]=debug` still enables events only inside the span.
-
`state::tests::postgres_tests::a_lost_open_set_invalidation_grants_a_revoked_channel_only_until_max_age`
runs two relay states on one database, with no pub/sub between them. For
each revocation (private, deleted, unlisted), it:
1. primes the reader pod;
2. revokes the channel in SQL and invalidates only the writer pod;
3. shows that a new reader is still granted the channel within the
window;
4. ages the cached set past the limit;
5. asserts that a new reader and an earlier cached reader are both
denied.
Dropping the age check fails it. Never caching the open set fails its
within-window control.
- `env_filter_tests::directive_filters_log_what_env_filter_logs` emits
events at every level for six targets, including prefix lookalikes. It
asserts that the filter built for each of 17 directive lists logs
exactly what `EnvFilter` logs for that list. Routing `buzz_relay=` to
`Targets` fails it.
- `state::tests::accessible_channels_join_member_and_open_halves` checks
the merge. The two existing scoped-invalidation tests now also assert
the open half.
- These state tests, and the two existing ones, were not in the `just
test-unit` allowlist. They are infra-free, so they are now selected by
exact name, and `scripts/run-tests.sh` mirrors that.
Identified debt, not fixed here: the per-reader member half keeps the
pre-existing unfenced read-then-insert (a raced fill only reaches that
reader, as before).
`handlers::req::tests::expiry_during_stalled_{history,search}_read_releases_permit_and_claim`
are not selected by any CI lane.
buzz-review-completed
🤖 Generated with [Claude Code](https://claude.com/claude-code)
---------
Signed-off-by: Luke Tornquist <tornquist@squareup.com>
Co-authored-by: Elrond <28d6302a099e5225b02c4155ac4236e4912603df2ab08dbfc2f4fef08ce598c8@buzz.block.builderlab.xyz>
Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>