perf(relay): index channel-id lookups and skip trace-only reads (#4647)

## Problem

`SELECT id, community_id FROM channels WHERE id = ANY($1) AND deleted_at
IS NULL` is the top **Load by waits (AAS)** on the Buzz Postgres writer.
Two independent causes compound, and both are fixed here.

### 1. No index can serve it

`channels` is `PRIMARY KEY (community_id, id)`, and every secondary
index leads with `community_id`:

| Index | Columns |
|---|---|
| *(primary key)* | `(community_id, id)` |
| `idx_channels_nip29_group` | `(community_id, nip29_group_id)` |
| `idx_channels_dm_hash` | `(community_id, participant_hash)` |
| `idx_channels_community_type` | `(community_id, channel_type)` |
| `idx_channels_community_visibility` | `(community_id, visibility)` |
| `idx_channels_created_by` | `(community_id, created_by)` |
| `idx_channels_ttl_expiry` | `(ttl_deadline)` *(partial)* |

The two tenant-independent lookups carry **no `community_id` predicate**
— deliberately:

- `Db::communities_of_channels` — `WHERE id = ANY($1) AND deleted_at IS
NULL`
- `Db::community_of_channel` — `WHERE id = $1 AND deleted_at IS NULL`

That independence is load-bearing, not an oversight: projecting a row's
*true* owning community regardless of the fetch query's `WHERE` clause
is what makes `Inv_NonInterference` non-vacuous. If the fetch ever
dropped its tenant scoping, this lookup would still report the real
label and the checker would catch the mismatch.

But a composite btree is only usable when its leading column is
constrained, so neither query can use the primary key, and nothing else
leads with `id`. **Both sequentially scan `channels` on every call.**

### 2. In production the result is discarded

Both call sites feed `record_read_message_rows` /
`record_read_by_id_rows`, which call `tracer.record(...)`. Production
binds `NoopTracer` (`crates/buzz-relay/src/state.rs`), whose `record`
body is empty.

The existing guard tests `trace_state`, which is `Some` for every
well-formed request — it only goes `None` on malformed pubkey bytes. So
the scan ran on the hot read path and its output was dropped. This is
the classic eager-argument bug: `log.debug("..." + expensiveCall())`
with no `isDebugEnabled()` check.

### 3. Multiplied per filter

The non-search call site sits **inside the phase-3 per-filter loop**, so
a `REQ` carrying N filters performed N sequential scans of `channels`
before responding.

## Changes

**`Tracer::enabled()`** — a capability check on the trait (the
`isDebugEnabled()` of this seam), defaulting to `true`. `NoopTracer`
overrides it to `false`, and both emitters in `req.rs` now gate on it,
skipping the trace-only DB read entirely in production.

**`migrations/0027_channels_id_lookup_index.sql`**

```sql
CREATE INDEX IF NOT EXISTS idx_channels_id_live
    ON channels (id) INCLUDE (community_id)
    WHERE deleted_at IS NULL;
```

- `INCLUDE (community_id)` — both queries select exactly `(id,
community_id)`, so this is covering and can be served index-only.
- Partial on `deleted_at IS NULL` — matches both predicates exactly,
excludes soft-deleted history, and lets Postgres skip the recheck.
- **Not `UNIQUE`.** `id` alone is *not* unique in this table —
`command_executor.rs` documents that `community_of_channel(channel_id)`
is ambiguous because the same channel id can appear under more than one
community. A unique index would encode a false constraint and fail to
build on any database already holding such a pair.

Worth keeping the index even though fix #1 removes the production
caller: it still runs under conformance, and `community_of_channel` has
the same problem on its own paths.

**`schema/schema.sql`** — mirrored, since a test asserts desired-state
parity.

## Conformance is unchanged

This is the part worth reviewing closely. Under a real tracer
`enabled()` returns `true` and **every emit happens exactly as before**
— the gate only skips *building* emit inputs when nothing observes them,
never an emit that would otherwise have been made. The coverage-breach
guard stays non-vacuous.

`CountingTracer` forwards `enabled()` to its inner tracer rather than
inheriting the `true` default. Both directions matter and both fail
silently:

- inheriting `true` over a `NoopTracer` would keep the overhead this PR
removes;
- hardcoding `false` over a live tracer would suppress the emits whose
absence `EmitGuard` reports as `ImplBug` — masking real breaches behind
expected ones.

Covered by a new regression test,
`counting_tracer_delegates_enabled_to_inner`, which asserts delegation
in both directions.

## Verification

- `cargo check -p buzz-conformance -p buzz-relay` — clean
- `cargo clippy --all-targets` — clean, zero warnings
- `cargo test -p buzz-conformance` — 6/6
- `cargo test -p buzz-relay --lib conformance` — 11/11
- `cargo test -p buzz-db --lib migration` — 7/7
- `just test-unit` (pre-push) — green

Migration-count assertions in `crates/buzz-db/src/migration.rs` were
bumped 26 → 27, with content assertions for 0027 following the existing
per-migration pattern (including a guard that it never becomes
`UNIQUE`).

## Open questions for reviewers

1. **Lock strategy.** Built *without* `CONCURRENTLY`, following
migration 0004's precedent, because sqlx runs each migration inside a
transaction and `CREATE INDEX CONCURRENTLY` cannot run in one. This
takes a brief `SHARE` lock on `channels` (blocks writes, not reads) —
small relative to `events`, but an operator preferring zero
write-blocking can pre-build it by hand and `IF NOT EXISTS` makes the
migration a no-op. I could not confirm whether sqlx 0.9 supports a `--
no-transaction` directive; if it does, that may be preferable.

2. **Diagnosis is static.** This comes from reading the source, not from
`EXPLAIN` against the live database. Worth confirming with `EXPLAIN
(ANALYZE, BUFFERS)` on the writer before/after — that also sizes the win
by revealing the real table size and row counts.

3. **Expected impact** scales with average filters-per-`REQ`, which I
did not measure. `pg_stat_statements` ordered by `total_exec_time` would
confirm this query drops off the top and show whether anything else is
scanning the same way.

Signed-off-by: Jemiah Westerman <jemiah@squareup.com>
This commit is contained in:
Jemiah Westerman
2026-08-04 10:59:54 -07:00
committed by GitHub
parent 0c33a8a55f
commit bc9e6528a7
7 changed files with 185 additions and 5 deletions

View File

@@ -315,6 +315,27 @@ pub trait Tracer: Send + Sync {
/// Record one trace step. Implementations MAY be no-ops in production
/// builds and write to JSONL in tests.
fn record(&self, step: TraceStep);
/// Whether recorded steps are actually observed.
///
/// Emitters on hot paths MUST consult this before doing work whose
/// *only* consumer is the trace — most importantly extra database
/// reads that project row labels independently of the fetch query
/// (the read-seam's `communities_of_channels` lookup). With a
/// discarding tracer that work is pure overhead.
///
/// This is the `log.isDebugEnabled()` of the trace seam. It exists to
/// let callers skip *building emit inputs*, never to let them skip an
/// emit they would otherwise have made: when this returns `true`
/// every seam must behave exactly as it did before the gate existed,
/// so the coverage-breach guard stays non-vacuous.
///
/// Defaults to `true` — a new tracer is assumed to observe steps until
/// it says otherwise. Wrappers that delegate to an inner tracer MUST
/// forward this method rather than inherit the default.
fn enabled(&self) -> bool {
true
}
}
/// A no-op tracer for production. Zero cost: the build can omit emission
@@ -324,4 +345,9 @@ pub struct NoopTracer;
impl Tracer for NoopTracer {
fn record(&self, _step: TraceStep) {}
/// Nothing is observed, so emitters should skip building inputs.
fn enabled(&self) -> bool {
false
}
}

View File

@@ -100,7 +100,7 @@ mod tests {
use super::*;
use std::collections::BTreeSet;
const TEST_DB_URL: &str = "postgres://buzz:buzz_dev@localhost:5432/buzz";
const TEST_DB_URL: &str = "postgres://buzz:buzz_dev@localhost:5432/buzz"; // sadscan:disable np.postgres.1
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
enum ConstraintKind {
@@ -561,7 +561,7 @@ mod tests {
let mut migrations: Vec<_> = MIGRATOR.iter().collect();
migrations.sort_by_key(|migration| migration.version);
assert_eq!(migrations.len(), 26);
assert_eq!(migrations.len(), 27);
assert_eq!(migrations[0].version, 1);
assert_eq!(&*migrations[0].description, "initial schema");
assert!(migrations[0]
@@ -919,6 +919,27 @@ mod tests {
assert!(heartbeat.contains("epoch"));
assert!(heartbeat.contains("INSERT INTO replica_heartbeat (id) VALUES (1)"));
assert!(heartbeat.contains("_operator_global_tables"));
// Channel-id lookup index (0027): serves the tenant-independent
// `channels` lookups that carry no community_id predicate, which no
// community_id-leading index can satisfy. Covering + partial so the
// planner can go index-only; asserted NOT UNIQUE because `id` alone is
// not unique in this table (the same channel id may exist under more
// than one community), so a unique index would encode a false
// constraint and fail to build on such a database.
assert_eq!(migrations[26].version, 27);
let channel_id_index = migrations[26].sql.as_str();
assert!(channel_id_index.contains("idx_channels_id_live"));
assert!(channel_id_index.contains("INCLUDE (community_id)"));
assert!(channel_id_index.contains("WHERE deleted_at IS NULL"));
assert!(
!channel_id_index.contains("CREATE UNIQUE INDEX"),
"channels.id is not unique across communities — index must not be UNIQUE",
);
assert!(
desired_schema.contains("idx_channels_id_live"),
"desired-state schema must carry the channel-id lookup index",
);
}
#[test]
@@ -1161,7 +1182,7 @@ mod tests {
run_migrations(&pool)
.await
.expect("retry succeeds after operator repair");
assert_eq!(applied_versions(&pool).await.last().copied(), Some(26));
assert_eq!(applied_versions(&pool).await.last().copied(), Some(27));
}
#[tokio::test]

View File

@@ -370,6 +370,16 @@ impl Tracer for CountingTracer {
.fetch_add(1, std::sync::atomic::Ordering::Relaxed);
self.inner.record(step);
}
/// Delegate, never inherit the `true` default. This wrapper is
/// transparent: whether emits are observed is a property of the
/// tracer underneath it. Returning `true` over a `NoopTracer` would
/// reintroduce the overhead the gate exists to remove; returning
/// `false` over a real tracer would suppress the emits whose absence
/// the `EmitGuard` reports as a coverage breach.
fn enabled(&self) -> bool {
self.inner.enabled()
}
}
impl EmitGuard {
@@ -455,6 +465,52 @@ mod tests {
}
}
/// Discarding tracer that reports `enabled() == false`, standing in
/// for the production `NoopTracer`.
#[derive(Debug, Default)]
struct DisabledTracer;
impl Tracer for DisabledTracer {
fn record(&self, _step: TraceStep) {}
fn enabled(&self) -> bool {
false
}
}
/// `CountingTracer` must forward `enabled()` to the tracer it wraps
/// rather than inherit the trait's `true` default. Both directions
/// matter, and getting either wrong is silent:
///
/// - over a disabled tracer, answering `true` would keep the hot-path
/// read-seam `channels` lookup running in production — the overhead
/// the gate exists to remove;
/// - over a live tracer, answering `false` would make gated emitters
/// skip emits during conformance runs, so the `EmitGuard` would
/// report `ImplBug` for seams that are in fact correct (or, worse,
/// mask a real breach behind an expected one).
#[test]
fn counting_tracer_delegates_enabled_to_inner() {
let (_guard, counting) = EmitGuard::arm(
Arc::new(DisabledTracer),
dummy_state(),
"delegates_disabled",
);
assert!(
!counting.enabled(),
"CountingTracer must report disabled when wrapping a discarding tracer"
);
let (_guard, counting) = EmitGuard::arm(
Arc::new(VecTracer::default()),
dummy_state(),
"delegates_live",
);
assert!(
counting.enabled(),
"CountingTracer must report enabled when wrapping an observing tracer"
);
}
fn dummy_state() -> AbstractState {
AbstractState {
resolved_community: CommunityLabel::from_uuid(Uuid::from_u128(0xA)),

View File

@@ -17,6 +17,12 @@ pub struct NoopTracer;
impl Tracer for NoopTracer {
fn record(&self, _step: TraceStep) {}
/// Nothing is observed, so emitters should skip building inputs —
/// including the read-seam's per-request `channels` lookup.
fn enabled(&self) -> bool {
false
}
}
/// JSONL-to-file tracer for tests + the CI replay job. Each `record` call

View File

@@ -334,7 +334,12 @@ pub async fn handle_req(
// (B) projection strategy and the missing-lookup ImplBug
// guard-rail. Skipped silently if `trace_state` is `None` (only
// happens on malformed pubkey, a separate failure path).
if let Some(state_snap) = trace_state.as_ref() {
// `tracer.enabled()` short-circuits the whole block on the production
// `NoopTracer`: the `communities_of_channels` lookup below is a
// `channels` read whose only consumer is `record_read_message_rows`,
// and this emit runs once PER FILTER. Gating on `trace_state` alone was
// not enough — that is `Some` for every well-formed request.
if let Some(state_snap) = trace_state.as_ref().filter(|_| state.tracer.enabled()) {
let row_channels: Vec<Option<uuid::Uuid>> =
events.iter().map(|e| e.channel_id).collect();
let distinct: Vec<uuid::Uuid> = {
@@ -659,7 +664,9 @@ async fn handle_search_req(
// level isn't bound to a single channel filter, the
// per-row `channel_id` carries the channel identity
// honestly.
if let Some(state_snap) = trace_state {
// Same `enabled()` gate as the non-search lane: skip the
// trace-only `channels` lookup when nothing observes the emit.
if let Some(state_snap) = trace_state.filter(|_| state.tracer.enabled()) {
let row_channels: Vec<Option<uuid::Uuid>> =
events.iter().map(|e| e.channel_id).collect();
let distinct: Vec<uuid::Uuid> = {

View File

@@ -0,0 +1,58 @@
-- ── Covering index for channel-id → community lookups ───────────────────────
-- `channels` is keyed PRIMARY KEY (community_id, id), and every secondary index
-- leads with community_id:
--
-- idx_channels_nip29_group (community_id, nip29_group_id)
-- idx_channels_dm_hash (community_id, participant_hash)
-- idx_channels_community_type (community_id, channel_type)
-- idx_channels_community_visibility (community_id, visibility)
-- idx_channels_created_by (community_id, created_by)
--
-- The tenant-independent lookups in buzz-db resolve a channel's owning
-- community *without* a community_id predicate — that independence is the
-- point (buzz-db/src/lib.rs: the read-seam projects a row's true label
-- regardless of the fetch query's WHERE clause, which is what makes
-- Inv_NonInterference non-vacuous):
--
-- Db::communities_of_channels SELECT id, community_id FROM channels
-- WHERE id = ANY($1) AND deleted_at IS NULL
-- Db::community_of_channel SELECT community_id FROM channels
-- WHERE id = $1 AND deleted_at IS NULL
--
-- A composite btree is only usable when its leading column is constrained, so
-- neither query can use the primary key and no other index leads with `id`.
-- Both therefore sequentially scan `channels` on every call. Observed as the
-- top "Load by waits (AAS)" on the staging writer (db.r8g.8xlarge, ~53% CPU).
--
-- INCLUDE (community_id): both queries select only (id, community_id), so the
-- index is covering and the planner can serve them index-only, with no heap
-- fetch for visible rows.
--
-- Partial on deleted_at IS NULL: matches both predicates exactly, keeps the
-- index off soft-deleted history, and lets Postgres skip re-checking the
-- predicate.
--
-- NOT UNIQUE, deliberately. `id` alone is not unique in this table —
-- handlers/command_executor.rs documents that community_of_channel(channel_id)
-- is ambiguous because the same channel id can appear under more than one
-- community. A unique index would encode a false constraint and would fail to
-- build on any database that already holds such a pair.
--
-- Lock note: built without CONCURRENTLY, matching migration 0004's precedent —
-- sqlx runs each migration inside a transaction and CREATE INDEX CONCURRENTLY
-- cannot run in one. This takes a SHARE lock on `channels` (blocking writes,
-- not reads) for the duration of the build. `channels` is a small table
-- relative to `events`, so this is expected to be brief, but on a large
-- brownfield database an operator may prefer to pre-build it by hand:
--
-- CREATE INDEX CONCURRENTLY idx_channels_id_live
-- ON channels (id) INCLUDE (community_id)
-- WHERE deleted_at IS NULL;
--
-- IF NOT EXISTS then makes this migration a no-op on that database.
--
-- Additive migration: previously applied files must not change checksum.
CREATE INDEX IF NOT EXISTS idx_channels_id_live
ON channels (id) INCLUDE (community_id)
WHERE deleted_at IS NULL;

View File

@@ -112,6 +112,12 @@ CREATE INDEX idx_channels_community_visibility ON channels (community_id, visibi
CREATE INDEX idx_channels_created_by ON channels (community_id, created_by);
CREATE INDEX idx_channels_ttl_expiry ON channels (ttl_deadline)
WHERE ttl_seconds IS NOT NULL AND archived_at IS NULL AND deleted_at IS NULL;
-- Tenant-independent channel-id → community lookups (Db::communities_of_channels,
-- Db::community_of_channel) carry no community_id predicate, so no
-- community_id-leading index can serve them. Covering + partial: index-only scan.
-- Not UNIQUE — the same channel id may exist under more than one community.
CREATE INDEX idx_channels_id_live ON channels (id) INCLUDE (community_id)
WHERE deleted_at IS NULL;
-- channels.community_id is immutable: a channel can never be re-tenanted.
-- (Conformance: "Migration lint forbids channel re-tenanting except through an