buzz-acp: channels subscribed via membership notification never deliver events — dynamic subscribe latches as successful on a fire-and-forget Ok
- Dominant language
- Rust
- Stars
- 32.7k
- Forks
- 4.3k
- Avg merge
- 1d 13h
- Merged PRs (30d)
- 253
Description
**Describe the bug**
When an agent is added to a channel that is created *after* buzz-acp starts, the harness takes the dynamic-subscription path in the membership-notification handler, reports no error, and records the channel as subscribed — but **no event in that channel is ever delivered to the agent**. The channel is a permanent black hole until the harness process restarts.
This is not a startup-race or first-message race. I sent four messages into the affected channel over a 19-minute window, two of them carrying a correct `p` mention tag on the agent's pubkey, and the harness logged absolutely nothing for any of them. Meanwhile the same agent, same process, kept responding normally in every channel that had been subscribed at startup.
The failure is silent in both directions: the sender sees a normally delivered message with no 👀, and the agent has no way to know a channel exists that it is supposed to be listening to.
**Steps to reproduce**
1. Start a managed agent in Buzz Desktop with `subscribe=Mentions`. Let it come up and confirm it responds in an existing channel.
2. From a *second* client (different pubkey), open a **new** DM with that agent, or create a new channel and add the agent as a member.
3. Send a message in that new channel that `p`-tags the agent.
4. The agent never wakes. No 👀 reaction, no reply, no log line.
5. Send more messages, including further `p`-tagged ones. Still nothing.
6. Restart Buzz Desktop. The channel is picked up by the startup subscription pass and works normally from then on.
**Expected behavior**
A channel subscribed via a membership notification should deliver events exactly like a channel subscribed at startup. If the subscription cannot be established, that should be visible in the log at WARN, and it should be retried.
**Version and platform**
- Buzz version: 0.5.3
- OS: macOS 13.7.8 (Ventura), Darwin 22.6.0, x86_64
- Harness: `buzz-acp`, `agent_cmd=claude-agent-acp`, model `opus[1m]`
- Harness config from the startup line:
`idle_timeout=900s max_turn=7200s agents=10 heartbeat=0s subscribe=Mentions dedup=Queue meh=Steer ignore_self=true context_limit=12 max_turns_per_session=0 presence=true typing=true memory=true permission_mode=bypassPermissions respond_to=allowlist(4)`
**Logs / additional context**
Agent log: `~/Library/Application Support/xyz.block.buzz.app/agents/logs/__.log`, ANSI stripped. All times UTC.
Two channels were created after the last harness start (`21:05:38Z`):
| Created | Channel | Creator | Result |
|---|---|---|---|
| `00:06:42Z` | `dfe88714-aae0-4cc0-9f07-03b9d5c0cc7a` | another agent | never delivered |
| `00:54:49Z` | `0582a51b-4370-495b-9e23-add84ac5d8dd` | second human client | never delivered |
The complete log record for both:
```
2026-08-03T00:06:42.916657Z INFO buzz_acp: membership notification: subscribing to new channel channel_id=dfe88714-aae0-4cc0-9f07-03b9d5c0cc7a
2026-08-03T00:54:49.942309Z INFO buzz_acp: membership notification: subscribing to new channel channel_id=0582a51b-4370-495b-9e23-add84ac5d8dd
```
That is the entirety of it. **There are zero WARN or ERROR tracing lines in the log after the `21:05:38Z` start** — 45 lines total, of which every `buzz_acp` tracing line is INFO and the remaining four are the session banner and a repeated Node-side `CLAUDE_SDK_CAN_USE_TOOL_SHADOWED` warning. So `send_subscribe` did not fail (no `subscribe REQ failed for channel …`), the relay did not send `CLOSED` (no `subscription … closed by relay: …`), and the rate-limit gate never armed (no `subscription … rate-limited — parking …`).
Events published into `0582a51b` after the subscribe, none of which produced any log line or delivery:
| Published | Event | `p`-tag on agent? |
|---|---|---|
| `00:54:50Z` | `48c25486fb64…` | yes |
| `01:11:52Z` | `2da1b035de50…` | no |
| `01:12:45Z` | `7af9ccc0cfe8…` | no |
| `01:13:53Z` | `707bf62c03bf…` | yes |
All four are stored on the relay and readable with `buzz messages get --channel 0582a51b-… `. The agent is a listed member (`buzz channels members`). The two `p`-tagged events satisfy the `require_mention` filter that `subscribe=Mentions` installs. The sender's pubkey is inside the agent's `respond_to=allowlist(4)`.
For contrast, in the same process at `01:01:36Z` — between events 1 and 2 above — a `p`-tagged message in a *startup-subscribed* channel was delivered and processed normally:
```
2026-08-03T01:01:36.620512Z INFO buzz_acp: non-cancelling steer ack received channel=b439b24e-… event_id=7b5ecab2… ack=Ok(Success)
```
Both channels are DMs. The only difference is startup subscription versus dynamic subscription.
---
### Where I got to in the code
I could not determine the final mechanism, and I want to be explicit about that rather than guess. Two things I *can* state from reading `main`:
**1. The dynamic path's error check is structurally incapable of catching a failure.**
`crates/buzz-acp/src/relay.rs:762-777` — `subscribe_channel_from` returns `Ok(())` as soon as the command is handed to the background task's channel. It is fire-and-forget; the `Ok` means "queued", not "REQ sent" and certainly not "relay accepted":
```rust
pub async fn subscribe_channel_from(...) -> Result<(), RelayError> {
self.cmd_tx.send(RelayCommand::Subscribe { channel_id, filter, replay_since })
.await
.map_err(|_| RelayError::ConnectionClosed)?;
debug!("queued subscribe for channel {channel_id}");
Ok(())
}
```
So in `crates/buzz-acp/src/lib.rs:2042-2048`:
```rust
tracing::info!(channel_id = %ch, "membership notification: subscribing to new channel");
if let Err(e) = relay.subscribe_channel_from(ch, filter, Some(ts)).await {
tracing::warn!("failed to subscribe to new channel {ch}: {e}");
} else {
subscribed_channel_ids.insert(ch);
}
```
the `Err` arm is effectively dead unless the background task is gone entirely, and `subscribed_channel_ids.insert(ch)` runs on a bare "queued" acknowledgement. Once inserted, any later membership notification for that channel takes the `"membership notification: channel already subscribed"` branch at `lib.rs:2040` and never retries. A channel that fails to subscribe is therefore latched into a permanently-subscribed-but-dead state for the life of the process. That matches the observed behaviour exactly, whatever the upstream cause turns out to be.
**2. The dynamic path is invisible at INFO, which is why this took hours to find.**
The startup path logs a success confirmation at `lib.rs:1537`:
```rust
tracing::info!("subscribed to channel {channel_id}");
```
The dynamic path logs the *intent* at INFO and then nothing on success. Every observability point past that is DEBUG — `"queued subscribe for channel …"` (`relay.rs:776`) and `"rate-gated: deferring REQ for channel … to rate_limited_pending"` (`relay.rs:1375`). At the default INFO level an operator sees "subscribing to new channel" and has no way to distinguish success from silent failure.
I initially misread this asymmetry as the bug itself — the absence of a `subscribed to channel` line for the two dead channels — before reading the source and finding that the dynamic path simply never emits one. Noting that so the log excerpt above isn't misinterpreted the same way.
**What I ruled out**
- Filter divergence. `resolve_dynamic_channel_filter` (`config.rs:1343`) and `resolve_channel_filters` (`config.rs:1241`) build an identical `ChannelFilter` in `Mentions` mode — same three kinds, same `require_mention`. Not the difference.
- Rate gating. The gate is only armed by the `rate-limited:` `CLOSED` handler at `relay.rs:2239`, which logs at WARN. No WARN in the log.
- Send failure. Logs at WARN (`relay.rs:1416`). Not present.
- Relay-side state. Both channels exist, the agent is a member of both, and every event is retrievable via the CLI.
- Dead or wedged session. The same process was actively serving another channel between the dropped events.
**What I could not check**
Whether the `REQ` frame physically reached the relay, and if so whether the relay registered it. That needs either DEBUG-level harness logs or a socket capture, neither of which I have for the window in question. It is possible this is relay-side rather than harness-side.
**Suggested fixes**
Independent of root cause, and roughly in priority order:
1. Don't latch `subscribed_channel_ids` on a fire-and-forget `Ok`. Confirm the subscription is live (EOSE for `ch-`, or an explicit ack from the background task) before marking it subscribed, and leave it retryable otherwise.
2. Emit a success confirmation on the dynamic path at INFO, mirroring `lib.rs:1537`, so a dead dynamic subscription is diagnosable from a normal log.
3. Add a periodic reconciliation between `subscribed_channel_ids` and the background task's `active_subscriptions` so a channel in this state self-heals instead of waiting for a process restart.
**Possibly related, not investigated**
`buzz dms list` returns `[]` on this machine while three DM channels exist and the agent is a member of all three. I have not looked into whether that shares a cause with the above.
**Related issues** — distinct from this one, but adjacent:
- #4127 — dead Claude Code session never recycled; bound channels go silent. Different: here the session is alive and demonstrably serving other channels in the same window.
- #4408 — dispatch loop wedges and *no* channel dispatches. Different: here dispatch works fine for startup-subscribed channels and fails only for dynamically subscribed ones.
Contributor guide
Assessment
This issue has not been assessed yet.