feat(acp): show where reply time goes after an agent @mention

[BradGroux]

Refs #2386.

Why this PR exists

Four simple agent replies in #2386 took 13–31 seconds, but the available event timestamps only showed the beginning and end of each turn. That left no way to tell whether the delay happened in queueing, runtime startup, model work, or reply publication.

This PR adds the first in-process timing slice after Buzz receives the mention.

What changed

• Record process-local monotonic boundaries for relay receipt, queue admission, ACP session resolution, prompt dispatch, first semantic model or tool output, first reply fan-out, and turn completion.
• Correlate those boundaries into content-free mention_reply_latency samples.
• Report rolling warm/cold p50, p95, and max summaries for each stage.
• Let observer-enabled mention subscriptions receive self-authored kind-9 replies for telemetry while preserving the normal self-dispatch guard.
• Prefer signed parent/root correlation over whichever turn is currently active, so delayed relay fanout cannot be assigned to a newer turn.
• Treat unmatched signed thread tags as authoritative negative evidence instead of falling back to the active turn.
• Use channel fallback only for replies with no signed thread tags, and fail closed when more than one turn is possible.
• Document a deterministic check and an opt-in warm/cold live benchmark.

What this measures

This slice measures harness_relay_receipt through harness_relay_fanout. It does not claim sender-publish-to-recipient-render timing.

Durations come from one process-local monotonic clock. RFC3339 and Nostr timestamps are correlation metadata only.

The new semantic timing events contain identifiers, path classification, durations, and sample counts. They do not include message content, prompts, model output, credentials, or tool arguments. Existing raw acp_read and acp_write observer events are unchanged and remain outside this new redaction guarantee.

Verification

• cargo fmt --all -- --check
• cargo clippy -p buzz-acp --all-targets --all-features -- -D warnings
• cargo test -p buzz-acp --no-fail-fast with ambient lazy-pool overrides removed: 673 library tests and 9 pool-lifecycle tests passed.
• just ci passed formatting, workspace strict Clippy, Desktop check, Tauri strict Clippy, web check, mobile format/analyze, Rust suites, 3,885 Desktop tests and build, 2,047 Tauri library tests plus 3 diagnostics, and the web build. The final mobile suite reached 1,021 passed and 1 skipped, then reproduced the unchanged current-main failure ChannelDetailPage keeps follow mode off while a tall newest message stays visible at mobile/test/features/channels/channel_detail_page_test.dart:1053. This branch has no mobile diff.

What remains

#2386 should stay open until the outer sender-publication and recipient-render or relay-acceptance boundaries are measured, hosted warm/cold baselines and explicit budgets exist, and a scheduled or blocking regression job is in place.

[BradGroux]

I refreshed this branch against current main and re-audited the correlation path instead of carrying the old implementation forward unchanged.

The original timing slice is still relevant, but the audit found two ways a delayed or flat-thread relay event could corrupt attribution:

• a delayed reply for turn A could be stamped with active turn B before its signed parent/root tags were considered;
• an unmatched flat reply could be assigned to B when completed turn A was also a valid candidate.

Head c366443ff0eeb6cc06b57c2a4fef6372c7b24b10 now gives signed parent/root correlation precedence. When a flat reply is genuinely ambiguous, the collector drops that sample rather than manufacturing a latency value, retires completed no-reply traces, and then recovers for later unambiguous replies. The added regressions cover both the cross-turn attribution failure and recovery after ambiguity.

Exact-head verification:

• cargo test -p buzz-acp --no-fail-fast — 627 library tests and 9 lifecycle tests passed.
• strict package Clippy and Rust formatting passed.
• an independent clean-context review found no remaining attribution or rebase-specific issue after the recovery hardening.

The scope remains intentionally narrow. This still does not measure sender publication, hosted relay acceptance, recipient rendering, or establish a latency budget, so #2386 should remain open.

[BradGroux]

Rebased this branch onto current block/buzz main at c55e421a0.

Head moved from 0f8661a2c to 40edf23fd. The latency patch was integrated around the newer ACP steering and Goose usage work already on main; the existing steering state and prompt behavior remain intact while the mention-to-reply timing boundaries stay scoped to the active turn.

Verification:

• Full buzz-acp suite passed: 651 library tests and 9 pool tests.
• Strict Clippy passed for buzz-acp with all targets and warnings denied.
• Desktop Biome, file-size, text-size, and pubkey-truncation checks passed.
• The full Desktop test suite, TypeScript typecheck, and production Vite build passed on the final rebased branch.
• git diff --check, DCO trailer checks, and the direct merge-base audit passed.

GitHub checks are rerunning on the new head.

[BradGroux]

Rebased onto current block/buzz main at b1b283cd4 and compared the branch again with #2460. #2460 remains narrower and stale: it stops at turn completion, while #2408 also observes actual reply fan-out and covers overlapping turns.

The rebase audit found one attribution bug. A reply with signed parent or root tags that matched no tracked trigger could fall back to the active channel turn and manufacture a plausible latency sample for unrelated work. Signed thread evidence is now authoritative: unmatched tags fail closed, and channel fallback is reserved for genuinely flat replies with no signed thread tags. A regression covers the active-turn misattribution case. The commit subject also now uses the contributor guide's allowed feat type.

Published head: f72f798128fa931d3d555fb1ff02c2dbd912ae97.

ACP formatting, strict Clippy, 673 library tests, and 9 pool-lifecycle tests pass. The full repository gate passed every stage before reproducing the unchanged current-main mobile failure at channel_detail_page_test.dart:1053; this branch has no mobile diff.

[BradGroux]

Rebased onto block/buzz main at ce3cf3cd2591f132f286fbc0a42a9e6699d0b08d and reviewed the new field report on #2386 against the current reply-publication path and this branch's measurement boundary.

The reported timings are useful and materially strengthen the case that hosted upstream/write-path latency deserves separate instrumentation. Two causal conclusions are only partial, though:

• x-envoy-upstream-service-time describes the Envoy-to-upstream path. It can include proxy queueing, shared-capacity contention, service wake-up, and application work; it is not a direct measure of application CPU.
• Ordinary agent replies are published by a fresh buzz CLI process. BuzzClient::new constructs a new HTTP client and submit_stored_event posts to /events. The harness's persistent WebSocket is used for inbound subscriptions and selected publish paths, but it does not remove the cold-connection term from the normal buzz messages send reply path. The measured cold penalty therefore cannot simply be subtracted to assert a remaining pure relay-acceptance time.

This does not invalidate the field report. It narrows what the data proves: the hosted upstream/write path is slow and variable, while the existing measurements do not isolate queueing, wake-up, proxy, or application service time from one another.

PR #2408 remains the correct in-process slice. Its firstOutputToReplyMs and totalMs boundaries end when the self-authored reply fans back to the harness, so they capture aggregate publication, relay acceptance, and fan-out but do not isolate boundary 7→8. I kept the branch scoped to content-free, process-local timing and did not expand it into hosted-relay instrumentation. #2386 should remain open for the outer sender-publication, hosted acceptance, and recipient-render boundaries and for explicit latency budgets.

Exact-head verification on 7b7344d41186947f3af49a37e10a31dce0a74c34:

• Full buzz-acp suite passed with the ambient lazy-pool override removed: 680 library tests and 9 pool-lifecycle tests, 0 failures.
• Rust formatting passed, and strict buzz-acp Clippy passed with all targets, all features, and warnings denied.
• Desktop policy/static checks, the full JavaScript suite, typecheck, and production build passed.
• git diff --check, conflict-marker scan, merge-base audit, and required DCO trailers passed.

The branch remains valid, #2460 remains narrower, and no current-main change supersedes the actual reply-fan-out correlation implemented here.

[BradGroux]

Review and rebase summary

Reviewed the PR for accuracy against current block/buzz main at d42d60d64 and rebased the branch onto that commit.

What this PR does

Adds content-free mention-to-reply latency instrumentation to buzz-acp. The harness emits prompt_dispatched and turn_first_output observer boundaries during each turn, and a LatencyCollector correlates them with event_received, event_queued, turn_started, session_resolved, turn_completed, and the first self-authored kind:9 reply observed on the relay. After both the reply and turn completion are observed, it emits a mention_reply_latency observer event with one sample plus rolling p50, p95, and max summaries for the most recent 100 samples on the same warm or cold path.

Accuracy review

• The is_semantic_turn_output function correctly excludes keepalive, lifecycle, usage, and capability-update frames from the first-output boundary, so time-to-first-output cannot be artificially shortened by non-semantic frames. The test prompt_emits_content_free_dispatch_and_first_output_boundaries verifies a keepalive does not close the boundary.
• All duration math uses monotonicMs (process-local monotonic clock). RFC3339 and Nostr created_at values are explicitly correlation-only — the README documents this constraint.
• The path classification (cold vs. warm vs. unknown) is based on is_new_session from session_resolved. Summaries never mix paths.
• The trace TTL (15 minutes) and summary window (100 samples) are bounded. The prune method evicts stale traces.
• Privacy: the latency events include IDs, path classification, durations, and sample counts only. No message content, prompts, model output, credentials, or tool arguments. The test confirms serialized events do not contain "private prompt" or "private model output".
• The benchmark README documents the current scope honestly: the start boundary is harness receipt, not sender publish; the end boundary is relay fanout, not recipient render. Issue Why did four simple agent replies take 13–31 seconds? #2386 should remain open until the missing outer boundaries are landed.
• No unwrap() or expect() in production paths. No new dependencies.

Rebase result

Head moved from 7b7344d41 to 2835ff226. No conflicts. git range-diff shows the patch is unchanged.

CI

DCO passes. Semgrep OSS and zizmor were pending at the time of this comment.