From 9b1c4f98e2981d6d89fbfa3154b8ef0b3b6ad334 Mon Sep 17 00:00:00 2001 From: Will Pfleger Date: Mon, 28 Sep 2026 16:36:40 -0400 Subject: [PATCH] =?UTF-8?q?=F0=9F=A4=96=20perf:=20bound=20long-thread=20au?= =?UTF-8?q?x=20reads=20and=20make=20query=20deadlines=20terminal=20(#7854)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Long threads (over ~100 replies) time out in desktop. The aux hop that loads reactions and other e-tag references builds its filter as one `tags @> …` term per id, joined with `OR`. Past about 100 ids the planner switches to walking each partition's primary key backward, expecting to stop early. When few rows actually match, it scans the whole community. With a dirty GIN pending list, a 188-reply thread never finishes. ### What changes - **Set-based e-tag reads (`buzz-db`).** The aux e-tag query now puts the id set behind a `MATERIALIZED` CTE and matches with `ANY`. Each e-tag read also runs under a transaction-local `statement_timeout` of 20 s. - **Terminal timeout contract (`buzz-relay`).** When a read hits the deadline, the client gets a terminal timeout (`CLOSED` for REQ, the timeout error for COUNT and search), not a retryable failure. - **Subscription lifecycle (`buzz-relay`).** The per-connection subscription map lock is now the lifecycle lock. Claims, replacement, client `CLOSE`, owner-checked timeout and search cleanup, revoke, and connection teardown all change the map, the registry, topic refcounts and terminal frames while holding it. As a result, a timed-out subscription's `CLOSED` goes out before any replacement with the same id can claim it, and claims made after teardown are refused. - **Dropped terminal frame disconnects (`buzz-relay`).** If the `CLOSED` for a retired subscription (owner-checked timeout or channel eviction) can't be queued, the relay cancels the connection instead of leaving the client holding a subscription that will never receive fan-out. A client-initiated `CLOSE` ack is exempt. - **COUNT under the same deadline (`buzz-db`).** The fast COUNT path runs e-tag counts under the same transaction-local 20 s cap as SELECT, so WS COUNT and HTTP `/count` produce the terminal timeout too. - **Replica reads surface the deadline (`buzz-db`).** When a replica-routed read is cancelled by `statement_timeout` (SQLSTATE `57014`), the error is returned instead of re-running the query on the writer, which would run the same slow statement. Other replica errors still fall back to the writer. `PLANS/REPLICA_FULL_READ_ROUTING_DESIGN.md` records the exception. - **Deadline handling (desktop).** Only the relay's `query timed out` counts as a query deadline. A client-side `request timed out` stays retryable. For one-shot reads a deadline is terminal: the global query retry (budget 1), thread-replies retry and reaction hydration don't re-send the same slow query. Reaction ids held back by a deadline are released when the channel is opened again, so reopening retries them while same-channel re-renders don't. Live subscriptions, in both the renderer and the native archive-sync socket, keep treating a deadline `CLOSED` as transient: they back off and resubscribe with the same filter instead of being dropped. - **Deadline handling (mobile).** Mobile recognizes the deadline on both transports: HTTP `503 {"error":"query timed out"}` and the WS `CLOSED` reason. - The root `ProviderScope` retry policy returns no retry for deadline errors and keeps Riverpod's default backoff for everything else. - Background thread-summary recounts don't retry a deadline. - Forum posts polling pauses while the last load settled on a deadline; reopening the forum retries. - A channel's newest-window load surfaces a deadline instead of falling back to legacy WS history, and the channel list's batched queries return "unavailable" on a deadline instead of fanning out to per-filter fallbacks. An unavailable batch is not treated as empty. Known last-message timestamps and unread state are kept, and unread catch-up moves `lastMessageAt` forward (never backward) the same way live events do, so a cold start with no known timestamp still gets one. - A live subscription that gets a deadline `CLOSED` backs off and resubscribes with the same filter. History requests still fail on it. - Settled load failures show a Retry control, matching desktop's thread-replies error card: a shared `LoadErrorView` on the channel timeline, forum thread and forum posts list, and an icon button beside the thread replies summary. While the thread query has no value, the thread page shows the route snapshot plus live, cached and optimistic replies, with the loading or error status still visible. - Other re-sends (reconnect, foreground resume, live events, the unread backstop, scroll) are not suppressed; each is bounded by the relay's 20 s statement deadline. - **Long-thread seeder.** `just seed-long-thread [replies]` posts one thread (default 187 replies) with some reactions to the local dev relay, for reproducing long threads in the apps. It uses a throwaway key, refuses non-loopback relays and ignores ambient `BUZZ_*` credentials. Writes are paced to fit the stock relay rate limit. **Lifecycle concurrency.** The lock serializes one connection's subscription changes. Other connections can still be delayed by pressure on the shared pubsub command queue, and by serial eviction loops waiting behind a blocked connection. This PR does not claim strict isolation between connections. **Recovery vs. load.** Clients stop automatic retries of the same one-shot read, but they don't remember deadlines across other triggers: reconnect, resume, live events and the unread backstop can each send the read again later, bounded by the 20 s statement deadline. A live subscription that hits the deadline resubscribes with its original filter under the existing 1–30 s backoff, and against a filter that keeps timing out it retries at the 30 s cap indefinitely, so the worst case is one bounded query per subscription every 30 s. `since` is deliberately not advanced to now on resubscribe, because that would skip events missed while the subscription was closed. Unchanged from `main`: when mobile's channel history sync fails with cached messages available, the cached messages are shown without the error or Retry control. ### Benchmark Local reproduction on an isolated bench stack (not committed): - PG16, migrations applied, one 188-reply thread plus 5M background events in the same community. - Each request replays the desktop thread-replies filter through the relay, with `include_aux` on. Times are total ms for 3 runs, with a 60 s client cap. GIN pending-list state is controlled with `VACUUM` (clean) or by refilling the pending list (dirty), and recorded per partition with `pgstatginindex`. Dirty runs held 402 pending pages on every partition's tags index at the start and end of each matrix. Clean runs held 0–1 pages (relay startup writes). | build | GIN pending state | limit 10 | 50 | 100 | 200 (188 ids) | |---|---|---|---|---|---| | `main` | clean | 26 / 16 / 13 | 56 / 51 / 52 | 92 / 93 / 95 | 662 / 639 / 641 | | `main` | dirty | 315 / 298 / 327 | 22141 / 15888 / 16769 | 28992 / 27819 / 28080 | timeout ×3 (>60 s) | | this PR | clean | 35 / 21 / 14 | 57 / 49 / 48 | 82 / 80 / 75 | 153 / 150 / 135 | | this PR | dirty | 290 / 254 / 251 | 1257 / 1204 / 1206 | 2432 / 2378 / 2382 | 4333 / 4706 / 5104 | Baseline `origin/main` `b37e47721`; this PR at `5f2650f5f`, whose e-tag read builders are identical to the current head. At head `1ad81d868` against `origin/main` `15d44dcce`, limit 200 measured 145–179 ms clean (`main` 683–715) and 4.41–4.51 s dirty (`main` timeout ×3). Every completed cell returns the same signed event set: 209 events, 187 replies at limit 200. With `include_aux` off, every cell is ≤66 ms. The thread-window loader (`select_aux`) is unchanged from `main`, and its timings and captured plans match `main`'s. Actual aux-hop statements captured from each relay binary with `auto_explain` (analyze + buffers), execution ms: | build | clean, 100 ids | clean, 188 ids | dirty, 100 ids | dirty, 188 ids | |---|---|---|---|---| | `main` (N-way `OR`) | 40 | 298 | 28785 | 62892 | | this PR (`MATERIALIZED` fence + `ANY`) | 23 | 45 | 1992 | 3539 | **What the fence changes** - On `main`, the planner combines `ORDER BY created_at … LIMIT` with an overestimated match count and walks each partition's primary key backward, expecting to stop early. With few real matches it scans the whole community: the dirty 188-id statement touches ~4.9M shared buffers on `main` vs ~0.6M with the fence. - The fence prevents that early-stop plan. Across the measured cases (1–188 ids, both pending states), the planner used the GIN tags index. The fence doesn't force GIN in general; a broad enough filter could still get a different plan. **Tradeoff:** the fence materializes every match before sorting. In this bench small limits stayed within run-to-run noise of `main`. A single hot id (5,000 reactions, limit 100) measured 30–34 ms unfenced vs 35 ms fenced. **Deadline:** each e-tag read (SELECT and COUNT) runs under a transaction-local `statement_timeout` of 20 s. It only tightens: a shorter operator timeout (`BUZZ_DB_STATEMENT_TIMEOUT_MS`) is kept. It's a per-statement limit, not a per-request one, so a request that runs several pages or hops can take longer than 20 s in total. The benchmark does not force the deadline. --------- Signed-off-by: Will Pfleger Signed-off-by: Duncan Co-authored-by: Duncan Co-authored-by: Hayt <211b96e6a2b7f45fd4047988976c7bbbeeda0c15f3ae7b32eec20834b5a55118@buzz.block.builderlab.xyz> --- Justfile | 9 +- PLANS/REPLICA_FULL_READ_ROUTING_DESIGN.md | 6 +- crates/buzz-db/src/error.rs | 12 + crates/buzz-db/src/runtime/migration.rs | 5 + crates/buzz-db/src/runtime/mod.rs | 5 + crates/buzz-db/src/runtime/tests.rs | 297 ++++++++ crates/buzz-db/src/store/event.rs | 367 +++++++++- crates/buzz-relay/src/api/bridge.rs | 473 ++++++++++++- crates/buzz-relay/src/api/mod.rs | 58 ++ crates/buzz-relay/src/connection.rs | 21 +- crates/buzz-relay/src/handlers/close.rs | 142 +++- crates/buzz-relay/src/handlers/count.rs | 20 +- crates/buzz-relay/src/handlers/req.rs | 655 ++++++++++++++++-- .../buzz-relay/src/handlers/side_effects.rs | 35 +- crates/buzz-relay/src/state.rs | 8 + .../src/native_relay_client_finite_tests.rs | 1 + .../src/native_relay_client_tests.rs | 26 + .../lib/renderScopedReactions.test.mjs | 27 + .../messages/lib/renderScopedReactions.ts | 28 +- ...nderScopedReactionHydration.jsdom-test.mjs | 124 ++++ .../lib/useRenderScopedReactionHydration.ts | 8 + .../messages/queryDeadlineRetry.test.mjs | 154 ++++ .../src/features/messages/useThreadReplies.ts | 6 +- .../profile/profileBatchResilience.test.mjs | 9 +- desktop/src/shared/api/queryClient.ts | 6 +- .../src/shared/api/relayClosedPolicy.test.mjs | 1 + desktop/src/shared/api/relayClosedPolicy.ts | 5 +- .../shared/api/relayClosedRecovery.test.mjs | 29 + desktop/src/shared/api/relayClosedRecovery.ts | 9 +- desktop/src/shared/lib/relayError.test.mjs | 38 +- desktop/src/shared/lib/relayError.ts | 11 + .../channels/channel_detail_page.dart | 11 +- .../channels/channel_messages_provider.dart | 2 + .../thread_summaries.dart | 3 +- .../features/channels/channels_provider.dart | 62 +- .../channels/thread_detail_helpers.dart | 20 + .../features/channels/thread_detail_page.dart | 12 +- .../thread_detail_page/message_list.dart | 13 + .../lib/features/forum/forum_posts_view.dart | 30 +- .../lib/features/forum/forum_thread_page.dart | 35 +- mobile/lib/main.dart | 35 +- .../lib/shared/relay/relay_closed_policy.dart | 74 +- mobile/lib/shared/relay/relay_session.dart | 7 +- .../lib/shared/widgets/load_error_view.dart | 47 ++ .../channels/channel_detail_page_test.dart | 292 ++++++++ .../channel_messages_provider_test.dart | 51 ++ .../channels/channels_provider_test.dart | 172 +++++ .../features/forum/forum_widgets_test.dart | 180 +++++ .../relay/relay_closed_policy_test.dart | 1 + .../relay_deadline_provider_retry_test.dart | 226 ++++++ .../test/shared/relay/relay_session_test.dart | 32 + schema/schema.sql | 4 + scripts/run-tests.sh | 16 +- scripts/seed-long-thread.sh | 62 ++ 54 files changed, 3769 insertions(+), 213 deletions(-) create mode 100644 desktop/src/features/messages/lib/useRenderScopedReactionHydration.jsdom-test.mjs create mode 100644 desktop/src/features/messages/queryDeadlineRetry.test.mjs create mode 100644 mobile/lib/shared/widgets/load_error_view.dart create mode 100644 mobile/test/shared/relay/relay_deadline_provider_retry_test.dart create mode 100755 scripts/seed-long-thread.sh diff --git a/Justfile b/Justfile index 6377b290db..2f29f5e2a3 100644 --- a/Justfile +++ b/Justfile @@ -461,7 +461,8 @@ test-unit: # `handlers::`: the wider set is mostly Postgres-backed, and five of its # non-postgres_tests cases only "pass" without a database by waiting out # the ~30s sqlx acquire timeout, so they do not belong in the infra-free - # unit job either. + # unit job either. The REQ subscription-lifecycle tests are picked by + # exact name for the same reason: the rest of handlers::req needs a DB. # The third clause adds the NIP-FI HTTP ingress and its router/config # neighbours: nip_fi_http, nip_fi_config, router, api::parse_query_tests, # and the Git transport off_mode_precedence_tests. All are infra-free @@ -472,7 +473,7 @@ test-unit: # because they live in the binary target; the nested # `tests::postgres_tests::` stays in the PostgreSQL lane. cargo nextest run -p buzz-relay --lib --bin buzz-relay \ - -E 'test(/^api::admin::/) + test(/^handlers::channel_authz::/) + test(/^handlers::moderation_authz::/) + test(/^handlers::side_effects::tests::/) + test(/^storage_sweep::tests::/) + test(/^nip_fi_http::tests::/) + test(/^nip_fi_config::tests::/) + test(/^readiness::tests::/) + test(/^router::tests::/) + test(/^api::parse_query_tests::/) + test(/^api::git::transport::off_mode_precedence_tests::/) + test(=state::tests::neither_a_confirmed_inactive_community_nor_a_failed_lookup_admits_the_socket) + (kind(bin) & (test(/^tests::/) + test(/^composition_tests::/)) - test(/^tests::postgres_tests::/))' + -E 'test(/^api::admin::/) + test(/^handlers::channel_authz::/) + test(/^handlers::moderation_authz::/) + test(/^handlers::side_effects::tests::/) + test(/^storage_sweep::tests::/) + test(/^nip_fi_http::tests::/) + test(/^nip_fi_config::tests::/) + test(/^readiness::tests::/) + test(/^router::tests::/) + test(/^api::parse_query_tests::/) + test(/^api::git::transport::off_mode_precedence_tests::/) + test(=state::tests::neither_a_confirmed_inactive_community_nor_a_failed_lookup_admits_the_socket) + test(=handlers::req::tests::timed_out_historical_read_deregisters_before_closed) + test(=handlers::req::tests::superseded_timeout_leaves_replacement_intact) + test(=handlers::req::tests::search_claim_retires_live_and_yields_to_replacement) + test(=handlers::req::tests::concurrent_claims_and_stale_teardowns_keep_the_last_owner) + test(=handlers::req::tests::timeout_closed_is_emitted_before_a_replacement_can_claim) + test(=handlers::req::tests::revoke_then_replacement_keeps_replacement_whole) + test(=handlers::req::tests::claims_after_connection_cleanup_are_refused) + test(=handlers::req::tests::dropped_terminal_frame_cancels_connection) + test(=handlers::req::tests::revoke_dropped_terminal_frame_cancels_connection) + (kind(bin) & (test(/^tests::/) + test(/^composition_tests::/)) - test(/^tests::postgres_tests::/))' # ACP author-gate and queue tests protect the trust boundary between # relay events and agent prompts. They are infra-free; ignored lifecycle # tests remain excluded and run in their dedicated integration lanes. @@ -565,6 +566,10 @@ relay: bootstrap _ensure-migrations set +o allexport cargo run -p buzz-relay +# Post one root + N replies (and a few reactions) to the local dev relay, for eyeballing long threads +seed-long-thread replies="187": + ./scripts/seed-long-thread.sh {{replies}} + # Start the relay with the built web UI served from it relay-web: bootstrap _ensure-migrations #!/usr/bin/env bash diff --git a/PLANS/REPLICA_FULL_READ_ROUTING_DESIGN.md b/PLANS/REPLICA_FULL_READ_ROUTING_DESIGN.md index b6442d4f6d..c64d7e048b 100644 --- a/PLANS/REPLICA_FULL_READ_ROUTING_DESIGN.md +++ b/PLANS/REPLICA_FULL_READ_ROUTING_DESIGN.md @@ -12,8 +12,10 @@ created: 2026-08-28 routing**: the read may be served from a read replica when `BUZZ_REPLICA_READ_MAX_AGE_MS` is set, subject to the soundness predicate `RoutePredicate::for_query` derives from the query shape. The seam fails closed -to the writer at every error and is a genuine no-op until the budget is -configured (`crates/buzz-db/src/lib.rs`). +to the writer on replica errors, with one deliberate exception: a statement +cancelled by `statement_timeout` (SQLSTATE `57014`) is surfaced rather than +re-run, because the writer would run the same slow statement. It is a genuine +no-op until the budget is configured (`crates/buzz-db/src/lib.rs`). ## Routing rule diff --git a/crates/buzz-db/src/error.rs b/crates/buzz-db/src/error.rs index e7d7f2d324..4f15cc2b24 100644 --- a/crates/buzz-db/src/error.rs +++ b/crates/buzz-db/src/error.rs @@ -84,5 +84,17 @@ pub enum DbError { LastOperator, } +impl DbError { + /// Whether Postgres cancelled the statement (SQLSTATE 57014: + /// `statement_timeout` or an explicit cancel). Re-running such a query on + /// the writer would only repeat the same expensive work. + pub fn is_statement_cancelled(&self) -> bool { + matches!( + self, + DbError::Sqlx(sqlx::Error::Database(db)) if db.code().as_deref() == Some("57014") + ) + } +} + /// Convenience alias for `Result`. pub type Result = std::result::Result; diff --git a/crates/buzz-db/src/runtime/migration.rs b/crates/buzz-db/src/runtime/migration.rs index 66e3645915..9eae1dc72b 100644 --- a/crates/buzz-db/src/runtime/migration.rs +++ b/crates/buzz-db/src/runtime/migration.rs @@ -767,6 +767,11 @@ mod postgres_tests { .as_str() .contains("CREATE INDEX idx_events_tags_gin")); assert!(!migrations[0].sql.as_str().contains("idx_events_tags_gin")); + // schema.sql (CI / isolated relay bootstrap) must carry the same index, + // or e-tag reads there run on plans prod never sees. + assert!(include_str!("../../../../schema/schema.sql").contains( + "CREATE INDEX idx_events_tags_gin ON events USING GIN (tags jsonb_path_ops)" + )); // NIP-AM (kind 44200) FTS exclusion: additive migration, never folded // into 0001 — folding would change 0001's checksum and break brownfield diff --git a/crates/buzz-db/src/runtime/mod.rs b/crates/buzz-db/src/runtime/mod.rs index 150c8f4768..bc1e0374c7 100644 --- a/crates/buzz-db/src/runtime/mod.rs +++ b/crates/buzz-db/src/runtime/mod.rs @@ -201,6 +201,8 @@ impl ReadSession { /// /// If the proved replica transaction fails mid-request, the session /// permanently degrades to the writer and the query is re-run there. + /// Exception: a statement cancelled by `statement_timeout` (57014) is + /// returned as-is, since the writer would run the same slow statement. /// The writer is always at or ahead of any replica replay position, so /// the degraded follow-up can only observe *more* than the proof-time /// snapshot, never less — fresher aux rows, the same failure semantics @@ -211,6 +213,9 @@ impl ReadSession { ReadSessionInner::Replica { tx, writer } => { match event::query_events_on(tx, q).await { Ok(rows) => return Ok(rows), + // A cancelled statement (timeout) would be just as slow on + // the writer; surface it instead of doubling the cost. + Err(e) if e.is_statement_cancelled() => return Err(e), Err(e) => { tracing::warn!( error = %e, diff --git a/crates/buzz-db/src/runtime/tests.rs b/crates/buzz-db/src/runtime/tests.rs index 21d0e73823..3aa8e90685 100644 --- a/crates/buzz-db/src/runtime/tests.rs +++ b/crates/buzz-db/src/runtime/tests.rs @@ -3313,5 +3313,302 @@ async fn floor_guard_blocks_updates_that_move_rows_below_the_fence() { drop_scratch_db(&admin, pool, &name).await; } +// ---- Statement-deadline cancellation vs. replica fallback ---------------- +// +// A replica read cancelled by `statement_timeout` (SQLSTATE 57014) must be +// surfaced, not re-run on the writer: the writer would be just as slow and +// the relay maps it to a distinct non-retried "query timed out". Every other +// replica failure keeps failing closed to the writer. + +/// Writer and replica scratch DBs holding one root plus an `e`-tagged reply +/// that mentions `mentioned` — the writer copy says "writer-reply" so a +/// writer re-run is observable. Returns the reply-targeted query shape. +struct EtagFixture { + admin: PgPool, + writer: PgPool, + wname: String, + replica: PgPool, + rname: String, + cid: CommunityId, + root_hex: String, + mentioned_hex: String, +} + +async fn e_tag_fixture(prefix: &str) -> EtagFixture { + let admin = PgPool::connect(&admin_url().await) + .await + .expect("connect admin"); + let (writer, wname) = create_scratch_db(&admin, &format!("{prefix}_w")).await; + let (replica, rname) = create_scratch_db(&admin, &format!("{prefix}_r")).await; + let author = nostr::Keys::generate(); + let mentioned = nostr::Keys::generate(); + let community = Uuid::new_v4(); + let channel = Uuid::new_v4(); + let base = 1_700_000_000u64; + let root = signed_event_at(&author, "root", base); + for (pool, content) in [(&writer, "writer-reply"), (&replica, "replica-reply")] { + seed_community_channel(pool, community, channel, &author).await; + insert_top_level(pool, community, channel, &root).await; + let reply = nostr::EventBuilder::new(nostr::Kind::Custom(9), content) + .tags([ + nostr::Tag::event(root.id), + nostr::Tag::public_key(mentioned.public_key()), + ]) + .custom_created_at(nostr::Timestamp::from(base + 10)) + .sign_with_keys(&author) + .expect("sign reply"); + insert_top_level(pool, community, channel, &reply).await; + crate::insert_mentions( + pool, + CommunityId::from_uuid(community), + &reply, + Some(channel), + ) + .await + .expect("insert mentions"); + } + EtagFixture { + admin, + writer, + wname, + replica, + rname, + cid: CommunityId::from_uuid(community), + root_hex: root.id.to_hex(), + mentioned_hex: mentioned.public_key().to_hex(), + } +} + +impl EtagFixture { + fn e_tag_query(&self) -> EventQuery { + let mut q = EventQuery::for_community(self.cid); + q.e_tags = Some(vec![self.root_hex.clone(), "00".repeat(32)]); + q + } + + /// A routed `Db` whose reader pool connects fresh (so it picks up any + /// `ALTER DATABASE` settings made on the replica), with the fence open + /// and a bounded budget so unpinned reads route to the replica. + async fn routed_db(&self) -> Db { + let base = admin_url().await; + let url = format!("{}/{}", &base[..base.rfind('/').expect("path")], self.rname); + let reader = PgPool::connect(&url).await.expect("connect reader"); + let mut db = Db::from_pools(self.writer.clone(), reader); + db.fence().force_open_for_tests(chrono::Utc::now()); + db.set_replica_read_max_age_for_tests(Some(std::time::Duration::from_secs(5))); + db + } + + async fn drop(self) { + drop_scratch_db(&self.admin, self.replica, &self.rname).await; + drop_scratch_db(&self.admin, self.writer, &self.wname).await; + } +} + +fn contents(rows: &[StoredEvent]) -> Vec<&str> { + rows.iter().map(|e| e.event.content.as_str()).collect() +} + +#[tokio::test] +#[ignore = "requires Postgres"] +async fn replica_statement_cancel_propagates_without_writer_rerun() { + let fx = e_tag_fixture("cxl").await; + // A short operator cap on the replica (kept, not raised, by the e-tag + // deadline), plus a lock that parks every `events` read past it: the + // heartbeat proof still succeeds, then the routed read is cancelled. + sqlx::query(sqlx::AssertSqlSafe(format!( + "ALTER DATABASE {} SET statement_timeout = '300ms'", + fx.rname + ))) + .execute(&fx.admin) + .await + .expect("set replica statement_timeout"); + let db = fx.routed_db().await; + let q = fx.e_tag_query(); + + // Healthy control: the replica serves before it is locked. + let rows = db.query_events_routed("t_cxl", &q).await.expect("healthy"); + assert!( + contents(&rows).contains(&"replica-reply"), + "fixture must route to replica" + ); + + let mut locker = fx.replica.begin().await.expect("begin locker"); + sqlx::query("LOCK TABLE events IN ACCESS EXCLUSIVE MODE") + .execute(&mut *locker) + .await + .expect("lock replica events"); + + let cancelled = |r: crate::Result<()>, what: &str| match r { + Err(e) => assert!(e.is_statement_cancelled(), "{what}: want 57014, got {e}"), + Ok(()) => panic!("{what}: replica cancel was re-run on the writer"), + }; + cancelled( + db.query_events_routed("t_cxl", &q).await.map(drop), + "query_events_routed", + ); + cancelled( + db.query_events_routed_bounded("t_cxl", &q).await.map(drop), + "query_events_routed_bounded", + ); + cancelled( + db.count_events_routed("t_cxl", &q).await.map(drop), + "count_events_routed", + ); + let root_id = hex::decode(&fx.root_hex).expect("hex"); + cancelled( + db.get_events_by_ids_routed("t_cxl", fx.cid, &[root_id.as_slice()]) + .await + .map(drop), + "get_events_by_ids_routed", + ); + + locker.rollback().await.expect("unlock"); + drop(db); + fx.drop().await; +} + +/// [`replica_statement_cancel_propagates_without_writer_rerun`] for the +/// request-scoped [`ReadSession`]: a cancelled aux read inside the proved +/// replica transaction surfaces 57014 and does not degrade to the writer. +#[tokio::test] +#[ignore = "requires Postgres"] +async fn read_session_statement_cancel_propagates_without_writer_rerun() { + let fx = e_tag_fixture("scxl").await; + let db = fx.routed_db().await; + let reader_tx = db + .read_pool + .as_ref() + .expect("reader pool") + .begin() + .await + .expect("begin reader tx"); + let mut session = ReadSession { + inner: ReadSessionInner::Replica { + tx: reader_tx, + writer: fx.writer.clone(), + }, + }; + let rows = session + .query_events(&fx.e_tag_query()) + .await + .expect("healthy"); + assert_eq!(contents(&rows), vec!["replica-reply"]); + + // Force the next statement in the session over a short cap. + let ReadSessionInner::Replica { tx, .. } = &mut session.inner else { + unreachable!() + }; + sqlx::query("SET LOCAL statement_timeout = '50ms'") + .execute(&mut **tx) + .await + .expect("cap session"); + let mut locker = fx.replica.begin().await.expect("begin locker"); + sqlx::query("LOCK TABLE events IN ACCESS EXCLUSIVE MODE") + .execute(&mut *locker) + .await + .expect("lock replica events"); + + match session.query_events(&fx.e_tag_query()).await { + Err(e) => assert!(e.is_statement_cancelled(), "want 57014, got {e}"), + Ok(rows) => panic!("cancel re-ran on the writer: {:?}", contents(&rows)), + } + assert!( + session.is_replica(), + "a cancel must not degrade the session" + ); + + locker.rollback().await.expect("unlock"); + drop(session); + drop(db); + fx.drop().await; +} + +#[tokio::test] +#[ignore = "requires Postgres"] +async fn replica_non_cancel_failure_still_falls_back_to_writer() { + let fx = e_tag_fixture("nfb").await; + let db = fx.routed_db().await; + let q = fx.e_tag_query(); + let rows = db.query_events_routed("t_nfb", &q).await.expect("healthy"); + assert!( + contents(&rows).contains(&"replica-reply"), + "fixture must route to replica" + ); + + // Break the replica after the proof point (heartbeat table intact). + sqlx::query("DROP TABLE events CASCADE") + .execute(&fx.replica) + .await + .expect("drop replica events"); + + for rows in [ + db.query_events_routed("t_nfb", &q).await, + db.query_events_routed_bounded("t_nfb", &q).await, + ] { + let rows = rows.expect("non-cancel failure must fall back"); + assert!( + contents(&rows).contains(&"writer-reply"), + "{:?}", + contents(&rows) + ); + } + assert_eq!( + db.count_events_routed("t_nfb", &q) + .await + .expect("count falls back"), + 1 + ); + + drop(db); + fx.drop().await; +} + +/// The `#p`-joined SELECT (fenced, `e.` column prefix) and the COUNT `ANY` +/// path, executed with real bound values rather than only rendered SQL. +#[tokio::test] +#[ignore = "requires Postgres"] +async fn e_tag_any_runs_with_real_binds_on_p_join_and_count() { + let fx = e_tag_fixture("pjn").await; + let mut q = fx.e_tag_query(); + + let rows = event::query_events(&fx.writer, &q) + .await + .expect("e-tag select"); + assert_eq!(contents(&rows), vec!["writer-reply"]); + assert_eq!( + event::count_events(&fx.writer, &q) + .await + .expect("e-tag count"), + 1 + ); + + q.p_tag_hex = Some(fx.mentioned_hex.clone()); + let rows = event::query_events(&fx.writer, &q) + .await + .expect("#p + e-tag select"); + assert_eq!(contents(&rows), vec!["writer-reply"]); + assert_eq!( + event::count_events(&fx.writer, &q) + .await + .expect("#p + e-tag count"), + 1 + ); + + q.p_tag_hex = Some("11".repeat(32)); + assert!(event::query_events(&fx.writer, &q) + .await + .expect("miss") + .is_empty()); + assert_eq!( + event::count_events(&fx.writer, &q) + .await + .expect("miss count"), + 0 + ); + + fx.drop().await; +} + #[path = "tests/thread_window_postgres_tests.rs"] mod thread_window_postgres_tests; diff --git a/crates/buzz-db/src/store/event.rs b/crates/buzz-db/src/store/event.rs index 6259a02c5d..23082102e9 100644 --- a/crates/buzz-db/src/store/event.rs +++ b/crates/buzz-db/src/store/event.rs @@ -503,13 +503,42 @@ pub(crate) async fn query_events_on( return Ok(vec![]); } + let mut qb = build_query_events_sql(q); + let rows = if q.e_tags.is_some() { + fetch_with_e_tag_deadline(conn, &mut qb).await? + } else { + qb.build().fetch_all(&mut *conn).await? + }; + + let mut out = Vec::with_capacity(rows.len()); + for row in rows { + if let Some(ev) = row_to_stored_event(row)? { + out.push(ev); + } + } + Ok(out) +} + +/// SQL for [`query_events_on`], after its match-nothing early returns. +fn build_query_events_sql(q: &EventQuery) -> QueryBuilder { let clamp = q.max_limit.unwrap_or(DEFAULT_MAX_PAGE_LIMIT); let limit_val = q.limit.unwrap_or(100).min(clamp); let offset_val = q.offset.unwrap_or(0); + // e-tag reads filter inside a MATERIALIZED CTE and sort/limit outside it. + // With `ORDER BY created_at LIMIT n` in the same scope, the planner + // overestimates matches and walks each partition's pkey backward, testing + // every community row against the id set; the fence keeps it on the GIN + // tags index. + let e_tag_fence = q.e_tags.is_some(); let mut qb: QueryBuilder = if let Some(ref p_hex) = q.p_tag_hex { // Join against event_mentions for #p-filtered queries (indexed). - let mut b = QueryBuilder::new( + let mut b = QueryBuilder::new(if e_tag_fence { + "WITH m AS MATERIALIZED (" + } else { + "" + }); + b.push( "SELECT e.id, e.pubkey, e.created_at, e.kind, e.tags, e.content, \ e.sig, e.received_at, e.channel_id \ FROM events e \ @@ -524,7 +553,12 @@ pub(crate) async fn query_events_on( b.push_bind(p_hex.to_ascii_lowercase()); b } else { - let mut b = QueryBuilder::new( + let mut b = QueryBuilder::new(if e_tag_fence { + "WITH m AS MATERIALIZED (" + } else { + "" + }); + b.push( "SELECT id, pubkey, created_at, kind, tags, content, sig, received_at, channel_id \ FROM events WHERE community_id = ", ); @@ -614,17 +648,7 @@ pub(crate) async fn query_events_on( // the dominant scroll-back cost (~1.7s/page on staging). if let Some(ref e_tags) = q.e_tags { if !e_tags.is_empty() { - qb.push(" AND ("); - for (i, hex_id) in e_tags.iter().enumerate() { - if i > 0 { - qb.push(" OR "); - } - // Build the JSONB literal: [["e",""]] - let containment = serde_json::json!([["e", hex_id]]); - qb.push(format!("{col_prefix}tags @> ")); - qb.push_bind(containment); - } - qb.push(")"); + push_e_tag_filter(&mut qb, col_prefix, e_tags); } } @@ -704,21 +728,58 @@ pub(crate) async fn query_events_on( // same second. No existing index covers this trailing column — Postgres // sorts in memory, which is fine at current scale. If query performance // degrades, add a composite index like `(pubkey, kind, created_at DESC, id ASC)`. - qb.push(format!( - " ORDER BY {col_prefix}created_at DESC, {col_prefix}id ASC LIMIT " - )); + if e_tag_fence { + qb.push(") SELECT * FROM m ORDER BY created_at DESC, id ASC LIMIT "); + } else { + qb.push(format!( + " ORDER BY {col_prefix}created_at DESC, {col_prefix}id ASC LIMIT " + )); + } qb.push_bind(limit_val); qb.push(" OFFSET ").push_bind(offset_val); + qb +} - let rows = qb.build().fetch_all(&mut *conn).await?; +/// Server-side deadline for e-tag (aux-closure / `#e`) reads, kept under the +/// desktop's 30 s request timeout so a runaway query is cancelled once no +/// client can still be waiting for it. It only ever tightens the effective +/// `statement_timeout`: a shorter operator cap (`BUZZ_DB_STATEMENT_TIMEOUT_MS`) +/// is kept, and a disabled (`0`) or longer one is lowered to 20 s. The limit is +/// per statement, not per request. +const E_TAG_STATEMENT_TIMEOUT_SQL: &str = "SELECT set_config('statement_timeout', \ + CASE WHEN current_setting('statement_timeout')::interval = interval '0' \ + OR current_setting('statement_timeout')::interval > interval '20s' \ + THEN '20s' ELSE current_setting('statement_timeout') END, true)"; - let mut out = Vec::with_capacity(rows.len()); - for row in rows { - if let Some(ev) = row_to_stored_event(row)? { - out.push(ev); - } - } - Ok(out) +/// Run an e-tag read under [`E_TAG_STATEMENT_TIMEOUT_SQL`] without changing the +/// deadline for anything else on `conn`. `begin()` opens a transaction on an +/// autocommit writer connection or a savepoint inside the replica's read +/// transaction; rolling it back (the read has no writes to keep) reverts the +/// transaction-local `set_config` in both cases. +async fn fetch_with_e_tag_deadline( + conn: &mut sqlx::PgConnection, + qb: &mut QueryBuilder, +) -> Result> { + let mut tx = sqlx::Connection::begin(&mut *conn).await?; + sqlx::query(E_TAG_STATEMENT_TIMEOUT_SQL) + .execute(&mut *tx) + .await?; + let rows = qb.build().fetch_all(&mut *tx).await?; + tx.rollback().await?; + Ok(rows) +} + +/// e-tag pushdown as one array-bound containment test instead of an N-way +/// `OR` chain, so planner cost does not scale with the number of referenced +/// ids (the thread aux hop sends one id per reply). +fn push_e_tag_filter(qb: &mut QueryBuilder, col_prefix: &str, e_tags: &[String]) { + let containments: Vec = e_tags + .iter() + .map(|hex_id| serde_json::json!([["e", hex_id]])) + .collect(); + qb.push(format!(" AND {col_prefix}tags @> ANY(")) + .push_bind(containments) + .push("::jsonb[])"); } pub(crate) fn row_to_stored_event(row: sqlx::postgres::PgRow) -> Result> { @@ -884,16 +945,7 @@ pub(crate) async fn count_events_on(conn: &mut sqlx::PgConnection, q: &EventQuer if let Some(ref e_tags) = q.e_tags { if !e_tags.is_empty() { - qb.push(" AND ("); - for (i, hex_id) in e_tags.iter().enumerate() { - if i > 0 { - qb.push(" OR "); - } - let containment = serde_json::json!([["e", hex_id]]); - qb.push(format!("{col_prefix}tags @> ")); - qb.push_bind(containment); - } - qb.push(")"); + push_e_tag_filter(&mut qb, col_prefix, e_tags); } } @@ -920,7 +972,16 @@ pub(crate) async fn count_events_on(conn: &mut sqlx::PgConnection, q: &EventQuer } } - let row = qb.build().fetch_one(&mut *conn).await?; + let row = if q.e_tags.as_deref().is_some_and(|e| !e.is_empty()) { + // Run under the same transaction-local deadline as `query_events_on` + // so a COUNT over a long thread cannot stall indefinitely either. + let rows = fetch_with_e_tag_deadline(conn, &mut qb).await?; + rows.into_iter() + .next() + .ok_or_else(|| DbError::InvalidData("COUNT returned no rows".to_string()))? + } else { + qb.build().fetch_one(&mut *conn).await? + }; let cnt: i64 = row.try_get("cnt")?; Ok(cnt) @@ -1842,7 +1903,8 @@ impl Db { /// seam is gated on `BUZZ_REPLICA_READ_MAX_AGE_MS` (default off): when /// unset, even covered-eligible queries stay on the writer, so merging /// this seam is a true no-op until the budget is configured. Every - /// failure fails closed to the writer. + /// failure fails closed to the writer, except a statement-timeout cancel + /// (57014), which is surfaced rather than re-run. #[datastore_span(name = "query_events_routed", system = "postgresql")] pub async fn query_events_routed( &self, @@ -1864,6 +1926,12 @@ impl Db { Self::record_route(path, "replica", reason); Ok(events) } + // A cancelled statement (timeout) would be just as slow on the + // writer; surface it instead of doubling the cost. + Err(e) if e.is_statement_cancelled() => { + Self::record_route(path, "replica", "statement_cancelled"); + Err(e) + } Err(e) => { // Mid-query replica failure: fail closed to the // writer rather than surfacing a routed error. @@ -1917,6 +1985,12 @@ impl Db { Self::record_route(path, "replica", reason); Ok(events) } + // A cancelled statement (timeout) would be just as slow on the + // writer; surface it instead of doubling the cost. + Err(e) if e.is_statement_cancelled() => { + Self::record_route(path, "replica", "statement_cancelled"); + Err(e) + } Err(e) => { tracing::warn!(path, "replica read failed; re-running on writer: {e}"); Self::record_route(path, "writer", "replica_error"); @@ -1975,6 +2049,12 @@ impl Db { Self::record_route(path, "replica", reason); Ok(count) } + // A cancelled statement (timeout) would be just as slow on the + // writer; surface it instead of doubling the cost. + Err(e) if e.is_statement_cancelled() => { + Self::record_route(path, "replica", "statement_cancelled"); + Err(e) + } Err(e) => { tracing::warn!(path, "replica count failed; re-running on writer: {e}"); Self::record_route(path, "writer", "replica_error"); @@ -2228,6 +2308,12 @@ impl Db { Self::record_route(path, "replica", reason); Ok(events) } + // A cancelled statement (timeout) would be just as slow on the + // writer; surface it instead of doubling the cost. + Err(e) if e.is_statement_cancelled() => { + Self::record_route(path, "replica", "statement_cancelled"); + Err(e) + } Err(e) => { tracing::warn!(path, "replica read failed; re-running on writer: {e}"); Self::record_route(path, "writer", "replica_error"); @@ -2348,6 +2434,41 @@ impl Db { } } +#[cfg(test)] +mod e_tag_filter_shape_tests { + use super::*; + + /// The aux closure sends one e-tag per reply. The id set must be one + /// array-bound predicate (never an N-way `OR`), and it must be filtered + /// inside a MATERIALIZED CTE with ORDER BY/LIMIT outside: in the same + /// scope the planner flips to a backward pkey walk over the whole + /// community (the long-thread timeout). + #[test] + fn e_tag_query_filters_in_materialized_fence_before_order_limit() { + let mut q = EventQuery::for_community(CommunityId::from_uuid(uuid::Uuid::nil())); + q.kinds = Some(vec![7]); + q.e_tags = Some((0..188).map(|i| format!("{i:064x}")).collect()); + let qb = build_query_events_sql(&q); + let sql = qb.sql().as_str().to_owned(); + + assert!(sql.starts_with("WITH m AS MATERIALIZED (SELECT ")); + assert_eq!(sql.matches("tags @> ANY(").count(), 1); + assert!(!sql.contains(" OR ")); + let fence_end = sql.find(") SELECT * FROM m ").expect("fence closes"); + assert!(sql.contains("::jsonb[])")); + assert!(!sql[..fence_end].contains("ORDER BY")); + assert!(!sql[..fence_end].contains("LIMIT")); + assert!(sql[fence_end..].contains("ORDER BY created_at DESC, id ASC LIMIT ")); + } + + #[test] + fn non_e_tag_query_is_not_fenced() { + let q = EventQuery::for_community(CommunityId::from_uuid(uuid::Uuid::nil())); + let qb = build_query_events_sql(&q); + assert!(!qb.sql().as_str().contains("MATERIALIZED")); + } +} + #[cfg(test)] mod postgres_tests { use super::*; @@ -2401,6 +2522,180 @@ mod postgres_tests { id } + /// Effective `statement_timeout` observed *inside* the e-tag deadline, and + /// the value restored on `conn` afterwards. + async fn deadline_inside_and_after(conn: &mut sqlx::PgConnection) -> (String, String) { + let mut qb = QueryBuilder::new("SELECT current_setting('statement_timeout')"); + let rows = fetch_with_e_tag_deadline(conn, &mut qb) + .await + .expect("deadline read"); + let inside: String = rows[0].get(0); + let after: String = sqlx::query_scalar("SHOW statement_timeout") + .fetch_one(&mut *conn) + .await + .expect("show timeout"); + (inside, after) + } + + #[tokio::test] + #[ignore = "requires Postgres"] + async fn e_tag_deadline_only_tightens_and_restores_timeout() { + let pool = setup_pool().await; + // (operator setting, expected effective value inside the read) + let cases = [("0", "20s"), ("5s", "5s"), ("1min", "20s")]; + for (setting, expected) in cases { + // Autocommit connection (writer path). + let mut conn = pool.acquire().await.expect("acquire"); + sqlx::query("SELECT set_config('statement_timeout', $1, false)") + .bind(setting) + .execute(&mut *conn) + .await + .expect("set session timeout"); + let restored: String = sqlx::query_scalar("SHOW statement_timeout") + .fetch_one(&mut *conn) + .await + .expect("show timeout"); + let (inside, after) = deadline_inside_and_after(&mut conn).await; + assert_eq!(inside, expected, "autocommit, operator {setting}"); + assert_eq!(after, restored, "autocommit restore, operator {setting}"); + + // Nested in an outer read transaction (replica path -> savepoint). + let mut tx = sqlx::Connection::begin(&mut *conn).await.expect("begin"); + let (inside, after) = deadline_inside_and_after(&mut tx).await; + assert_eq!(inside, expected, "savepoint, operator {setting}"); + assert_eq!(after, restored, "savepoint restore, operator {setting}"); + tx.rollback().await.expect("rollback outer"); + + sqlx::query("RESET statement_timeout") + .execute(&mut *conn) + .await + .expect("reset"); + } + } + + #[tokio::test] + #[ignore = "requires Postgres"] + async fn e_tag_deadline_restores_timeout_after_error() { + let pool = setup_pool().await; + let mut conn = pool.acquire().await.expect("acquire"); + sqlx::query("SET statement_timeout = '1min'") + .execute(&mut *conn) + .await + .expect("set session timeout"); + // Autocommit connection (writer path). + let mut qb = QueryBuilder::new("SELECT 1/0"); + let err = fetch_with_e_tag_deadline(&mut conn, &mut qb).await; + assert!(err.is_err(), "division by zero must fail"); + let after: String = sqlx::query_scalar("SHOW statement_timeout") + .fetch_one(&mut *conn) + .await + .expect("connection usable after error"); + assert_eq!(after, "1min", "autocommit restore"); + + // Nested in an outer read transaction (replica path -> savepoint): + // the failed savepoint must roll back and leave the outer tx usable. + let mut tx = sqlx::Connection::begin(&mut *conn).await.expect("begin"); + let mut qb = QueryBuilder::new("SELECT 1/0"); + let err = fetch_with_e_tag_deadline(&mut tx, &mut qb).await; + assert!(err.is_err(), "division by zero must fail"); + let after: String = sqlx::query_scalar("SHOW statement_timeout") + .fetch_one(&mut *tx) + .await + .expect("outer transaction usable after savepoint error"); + assert_eq!(after, "1min", "savepoint restore"); + tx.rollback().await.expect("rollback outer"); + sqlx::query("RESET statement_timeout") + .execute(&mut *conn) + .await + .expect("reset"); + } + + /// Pins the dispatch: an e-tag read through the production + /// `query_events_on` is cancelled at the 20 s deadline even with the + /// session timeout disabled, while `events` is locked. (Slow by design.) + #[tokio::test] + #[ignore = "requires Postgres"] + async fn e_tag_read_is_cancelled_at_deadline_when_timeout_disabled() { + let pool = setup_pool().await; + let community = CommunityId::from_uuid(make_test_community(&pool).await); + let mut locker = pool.begin().await.expect("begin locker"); + sqlx::query("LOCK TABLE events IN ACCESS EXCLUSIVE MODE") + .execute(&mut *locker) + .await + .expect("lock events"); + + let mut conn = pool.acquire().await.expect("acquire"); + sqlx::query("SET statement_timeout = 0") + .execute(&mut *conn) + .await + .expect("disable timeout"); + let mut q = EventQuery::for_community(community); + q.e_tags = Some(vec!["00".repeat(32)]); + let started = std::time::Instant::now(); + let result = tokio::time::timeout( + std::time::Duration::from_secs(40), + query_events_on(&mut conn, &q), + ) + .await + .expect("deadline must fire before the 40 s guard"); + let err = result.expect_err("locked read must be cancelled"); + assert!(err.is_statement_cancelled(), "want 57014, got {err}"); + assert!(started.elapsed() >= std::time::Duration::from_secs(19)); + + locker.rollback().await.expect("unlock"); + sqlx::query("RESET statement_timeout") + .execute(&mut *conn) + .await + .expect("reset"); + } + + /// Pins the dispatch: a COUNT with an e-tag filter through the production + /// `count_events_on` is cancelled at the 20 s deadline even with the + /// session timeout disabled, while `events` is locked. Connection and + /// setting are restored afterwards. (Slow by design.) + #[tokio::test] + #[ignore = "requires Postgres"] + async fn count_events_cancels_at_e_tag_deadline_when_timeout_disabled() { + let pool = setup_pool().await; + let community = CommunityId::from_uuid(make_test_community(&pool).await); + let mut locker = pool.begin().await.expect("begin locker"); + sqlx::query("LOCK TABLE events IN ACCESS EXCLUSIVE MODE") + .execute(&mut *locker) + .await + .expect("lock events"); + + let mut conn = pool.acquire().await.expect("acquire"); + sqlx::query("SET statement_timeout = 0") + .execute(&mut *conn) + .await + .expect("disable timeout"); + let mut q = EventQuery::for_community(community); + q.e_tags = Some(vec!["00".repeat(32)]); + let started = std::time::Instant::now(); + let result = tokio::time::timeout( + std::time::Duration::from_secs(40), + count_events_on(&mut conn, &q), + ) + .await + .expect("deadline must fire before the 40 s guard"); + let err = result.expect_err("locked COUNT must be cancelled"); + assert!(err.is_statement_cancelled(), "want 57014, got {err}"); + assert!(started.elapsed() >= std::time::Duration::from_secs(19)); + + // Connection and session timeout are restored after the error. + let after: String = sqlx::query_scalar("SHOW statement_timeout") + .fetch_one(&mut *conn) + .await + .expect("connection usable after cancellation"); + assert_eq!(after, "0", "timeout must be restored to disabled"); + + locker.rollback().await.expect("unlock"); + sqlx::query("RESET statement_timeout") + .execute(&mut *conn) + .await + .expect("reset"); + } + #[tokio::test] #[ignore = "requires Postgres"] async fn event_insert_in_existing_transaction_rolls_back_with_caller() { diff --git a/crates/buzz-relay/src/api/bridge.rs b/crates/buzz-relay/src/api/bridge.rs index 13437d9c0d..b5aa6d553b 100644 --- a/crates/buzz-relay/src/api/bridge.rs +++ b/crates/buzz-relay/src/api/bridge.rs @@ -22,7 +22,7 @@ use crate::handlers::ingest::{IngestAuth, IngestError}; use crate::nip_fi_http::{admit_nip_fi_http_on_state, Nip98Proof}; use crate::state::AppState; -use super::{api_error, internal_error, not_found, parse_query_or_400}; +use super::{api_error, db_read_error, internal_error, not_found, parse_query_or_400}; mod thread_roots; mod thread_window; @@ -772,7 +772,7 @@ async fn handle_channel_window_filter( &mut AuxReader::Session(&mut session), ) .await - .map_err(|e| internal_error(&format!("window aux error: {e}")))?; + .map_err(|e| db_read_error("window aux error", &e))?; for se in aux_events { if !seen_aux.insert(se.event.id) { continue; @@ -1635,7 +1635,7 @@ async fn query_events_authed( &mut AuxReader::Routed(&state.db, "bridge_thread_aux"), ) .await - .map_err(|e| internal_error(&format!("thread aux query error: {e}")))?; + .map_err(|e| db_read_error("thread aux query error", &e))?; for se in aux_events { if !seen_aux.insert(se.event.id) || !event_in_accessible_channel(&se, &accessible_channels) @@ -1792,7 +1792,7 @@ async fn query_events_authed( } } Err(e) => { - return Err(internal_error(&format!("query error: {e}"))); + return Err(db_read_error("query error", &e)); } } } @@ -2058,7 +2058,7 @@ async fn count_events_authed( match state.db.count_events_routed("bridge_count", &query).await { Ok(n) => total += n as u64, Err(e) => { - return Err(internal_error(&format!("count error: {e}"))); + return Err(db_read_error("count error", &e)); } } } else { @@ -2093,7 +2093,7 @@ async fn count_events_authed( } } Err(e) => { - return Err(internal_error(&format!("count error: {e}"))); + return Err(db_read_error("count error", &e)); } } } @@ -2129,7 +2129,7 @@ async fn count_events_authed( match state.db.count_events_routed("bridge_count", &query).await { Ok(n) => total += n as u64, Err(e) => { - return Err(internal_error(&format!("count error: {e}"))); + return Err(db_read_error("count error", &e)); } } } else { @@ -2163,7 +2163,7 @@ async fn count_events_authed( } } Err(e) => { - return Err(internal_error(&format!("count error: {e}"))); + return Err(db_read_error("count error", &e)); } } } @@ -2314,7 +2314,7 @@ async fn handle_bridge_search( .db .get_events_by_ids_routed("bridge_search_hydrate", tenant.community(), &id_refs) .await - .map_err(|e| internal_error(&format!("search fetch error: {e}")))?; + .map_err(|e| db_read_error("search fetch error", &e))?; // Build lookup map to preserve FTS relevance ordering. let event_map: std::collections::HashMap<[u8; 32], &buzz_core::StoredEvent> = stored_events @@ -7606,4 +7606,459 @@ mod postgres_tests { drop_scratch(&admin2, replica_pool, &replica_name).await; }); } + + // ── Statement-cancel propagation through every routed-read caller ───────── + // + // A replica whose `events` table is locked past its 300ms operator + // `statement_timeout` cancels every routed read with 57014, which the + // routed helpers now propagate instead of re-running on the writer. Every + // COUNT arm (fast/fallback × with/without `#h`) and search hydrate must + // then answer with the stable timeout contract on both transports: + // HTTP 503 `query timed out`, WS CLOSED `error: query timed out`. The + // ordinary-error controls rename `events` so reads fail with 42P01 and + // must stay a generic 500 / raw WS error. + + struct CancelFixture { + admin: sqlx::PgPool, + writer: sqlx::PgPool, + replica: sqlx::PgPool, + names: [String; 2], + state: Arc, + host: String, + community: buzz_core::CommunityId, + channel: String, + root: String, + reader: Keys, + } + + async fn cancel_fixture() -> CancelFixture { + use buzz_db::channel::{ChannelType, ChannelVisibility}; + let admin_url = crate::test_support::database_url(); + let admin = sqlx::PgPool::connect(&admin_url).await.expect("admin pool"); + let base = &admin_url[..admin_url.rfind('/').expect("db path")]; + let community = uuid::Uuid::new_v4(); + let channel = uuid::Uuid::new_v4(); + let host = format!("cancel-{}.local", community.simple()); + let author = Keys::generate(); + let root = EventBuilder::new(Kind::Custom(9), "root needle") + .tag(Tag::parse(["h", &channel.to_string()]).expect("h")) + .sign_with_keys(&author) + .expect("sign root"); + let mut pools = Vec::new(); + let mut names = Vec::new(); + for role in ["w", "r"] { + let name = format!("cancel_{role}_{}", uuid::Uuid::new_v4().simple()); + sqlx::query(sqlx::AssertSqlSafe(format!("CREATE DATABASE {name}"))) + .execute(&admin) + .await + .expect("create scratch db"); + if role == "r" { + sqlx::query(sqlx::AssertSqlSafe(format!( + "ALTER DATABASE {name} SET statement_timeout = '300ms'" + ))) + .execute(&admin) + .await + .expect("replica statement_timeout"); + } + let pool = sqlx::PgPool::connect(&format!("{base}/{name}")) + .await + .expect("connect scratch"); + buzz_db::migration::run_migrations(&pool) + .await + .expect("migrate"); + sqlx::query("INSERT INTO communities (id, host) VALUES ($1, $2)") + .bind(community) + .bind(&host) + .execute(&pool) + .await + .expect("seed community"); + let cid = buzz_core::CommunityId::from_uuid(community); + buzz_db::channel::create_channel_with_id( + &pool, + cid, + channel, + &format!("cancel-{}", channel.simple()), + ChannelType::Stream, + ChannelVisibility::Open, + None, + author.public_key().to_bytes().as_slice(), + None, + ) + .await + .expect("create channel"); + buzz_db::Db::from_pool(pool.clone()) + .insert_event(cid, &root, Some(channel)) + .await + .expect("insert root"); + pools.push(pool); + names.push(name); + } + let replica = pools.pop().expect("replica"); + let writer = pools.pop().expect("writer"); + + let mut config = crate::config::Config::from_env().expect("config"); + config.redis_url = + std::env::var("REDIS_URL").unwrap_or_else(|_| "redis://127.0.0.1:6379".to_string()); + config.relay_url = "wss://cancel-test.local".to_string(); + config.require_auth_token = false; + config.require_relay_membership = false; + let mut db = buzz_db::Db::from_pools(writer.clone(), replica.clone()); + db.fence().force_open_for_tests(chrono::Utc::now()); + db.set_replica_read_max_age_for_tests(Some(std::time::Duration::from_secs(5))); + let redis_pool = deadpool_redis::Config::from_url(&config.redis_url) + .create_pool(Some(deadpool_redis::Runtime::Tokio1)) + .expect("redis pool"); + let pubsub = Arc::new( + buzz_pubsub::PubSubManager::new(&config.redis_url, redis_pool.clone()) + .await + .expect("pubsub"), + ); + let (mut state, _audit_shutdown) = crate::state::AppState::new( + config.clone(), + db.clone(), + redis_pool, + buzz_audit::AuditService::new(writer.clone()), + pubsub, + buzz_auth::AuthService::new(config.auth.clone()), + buzz_search::SearchService::new(writer.clone()), + Arc::new(buzz_workflow::WorkflowEngine::new( + db, + buzz_workflow::WorkflowConfig::default(), + )), + Keys::generate(), + buzz_media::MediaStorage::new(&config.media).expect("media storage"), + ); + state.nip98_replay = Arc::new(AlwaysFreshReplayGuard); + CancelFixture { + admin, + writer, + replica, + names: [names[0].clone(), names[1].clone()], + state: Arc::new(state), + host, + community: buzz_core::CommunityId::from_uuid(community), + channel: channel.to_string(), + root: root.id.to_hex(), + reader: Keys::generate(), + } + } + + impl CancelFixture { + /// The four COUNT arms: fast (fully pushable) and fallback (`#t` is + /// not pushable, `#e` still reaches SQL), each with and without `#h`. + fn count_cases(&self) -> Vec<(&'static str, serde_json::Value)> { + let e = [&self.root]; + let h = [&self.channel]; + vec![ + ( + "fast #h", + serde_json::json!({"kinds": [9], "#h": h, "#e": e}), + ), + ( + "fallback #h", + serde_json::json!({"kinds": [9], "#h": h, "#e": e, "#t": ["x"]}), + ), + ("fast no-#h", serde_json::json!({"kinds": [9], "#e": e})), + ( + "fallback no-#h", + serde_json::json!({"kinds": [9], "#e": e, "#t": ["x"]}), + ), + ] + } + + fn search_filter(&self) -> serde_json::Value { + serde_json::json!({"kinds": [9], "#h": [&self.channel], "search": "needle"}) + } + + async fn http(&self, uri: &str, filter: &serde_json::Value) -> (StatusCode, Value) { + use axum::body::Body; + use axum::http::{header, Request}; + use tower::ServiceExt; + let resp = crate::router::build_router(self.state.clone()) + .oneshot( + Request::builder() + .method("POST") + .uri(uri) + .header(header::HOST, &self.host) + .header("x-pubkey", self.reader.public_key().to_hex()) + .header("content-type", "application/json") + .body(Body::from(serde_json::to_vec(&[filter]).expect("json"))) + .expect("request"), + ) + .await + .expect("oneshot"); + let status = resp.status(); + let bytes = axum::body::to_bytes(resp.into_body(), usize::MAX) + .await + .expect("body"); + ( + status, + serde_json::from_slice(&bytes).unwrap_or(Value::Null), + ) + } + + /// Drive a WS frame handler and return the first frame it sends. + async fn ws(&self, drive: F) -> String + where + F: FnOnce(Arc) -> Fut, + Fut: std::future::Future, + { + let (conn, mut send_rx) = self.ws_conn(); + drive(conn).await; + match send_rx.try_recv().expect("handler sent a frame") { + axum::extract::ws::Message::Text(t) => t.to_string(), + other => panic!("expected text frame, got {other:?}"), + } + } + + /// An authenticated reader connection and its outbound frame queue. + fn ws_conn( + &self, + ) -> ( + Arc, + tokio::sync::mpsc::Receiver, + ) { + let (send_tx, send_rx) = tokio::sync::mpsc::channel(64); + let (ctrl_tx, _ctrl_rx) = tokio::sync::mpsc::channel(4); + let conn = Arc::new(crate::connection::ConnectionState { + conn_id: uuid::Uuid::new_v4(), + tenant: TenantContext::resolved(self.community, self.host.clone()), + remote_addr: "127.0.0.1:1234".parse().expect("addr"), + auth_state: std::sync::Mutex::new(crate::connection::AuthState::Authenticated( + buzz_auth::AuthContext { + pubkey: self.reader.public_key(), + scopes: Vec::new(), + channel_ids: None, + auth_method: buzz_auth::AuthMethod::Nip42, + agent_owner_pubkey: None, + }, + )), + subscriptions: Arc::new(tokio::sync::Mutex::new(Default::default())), + send_tx, + ctrl_tx, + cancel: tokio_util::sync::CancellationToken::new(), + backpressure_count: Arc::new(std::sync::atomic::AtomicU8::new(0)), + grace_limit: 3, + }); + (conn, send_rx) + } + + async fn ws_count(&self, filter: &serde_json::Value) -> String { + let filter: nostr::Filter = serde_json::from_value(filter.clone()).expect("filter"); + let state = self.state.clone(); + self.ws(|conn| { + crate::handlers::count::handle_count("c".into(), vec![filter], conn, state) + }) + .await + } + + async fn ws_search(&self) -> String { + let filter: nostr::Filter = + serde_json::from_value(self.search_filter()).expect("filter"); + let state = self.state.clone(); + self.ws(|conn| { + crate::handlers::req::handle_req("s".into(), vec![filter], vec![None], conn, state) + }) + .await + } + + async fn drop(self) { + drop(self.state); + for (pool, name) in [ + (self.writer, &self.names[0]), + (self.replica, &self.names[1]), + ] { + pool.close().await; + let _ = sqlx::query(sqlx::AssertSqlSafe(format!( + "DROP DATABASE IF EXISTS {name} WITH (FORCE)" + ))) + .execute(&self.admin) + .await; + } + } + } + + #[tokio::test] + #[ignore = "requires Postgres"] + async fn routed_read_cancel_maps_to_timeout_contract_on_count_and_search() { + let fx = cancel_fixture().await; + + // Healthy controls: every arm and search hydrate serve before the lock. + for (arm, filter) in fx.count_cases() { + let (status, body) = fx.http("/count", &filter).await; + assert_eq!(status, StatusCode::OK, "healthy HTTP COUNT {arm}: {body}"); + let frame = fx.ws_count(&filter).await; + assert!( + frame.starts_with(r#"["COUNT""#), + "healthy WS COUNT {arm}: {frame}" + ); + } + let (status, body) = fx.http("/query", &fx.search_filter()).await; + assert_eq!(status, StatusCode::OK, "healthy HTTP search: {body}"); + assert!( + body.to_string().contains("root needle"), + "search hit: {body}" + ); + let frame = fx.ws_search().await; + assert!(frame.contains("root needle"), "healthy WS search: {frame}"); + + let mut locker = fx.replica.begin().await.expect("begin locker"); + sqlx::query("LOCK TABLE events IN ACCESS EXCLUSIVE MODE") + .execute(&mut *locker) + .await + .expect("lock replica events"); + + let closed = |sub: &str| { + format!( + r#"["CLOSED","{sub}","{}"]"#, + crate::handlers::req::QUERY_TIMED_OUT_CLOSED + ) + }; + for (arm, filter) in fx.count_cases() { + let (status, body) = fx.http("/count", &filter).await; + assert_eq!( + (status, body["error"].as_str()), + ( + StatusCode::SERVICE_UNAVAILABLE, + Some(super::super::QUERY_TIMED_OUT) + ), + "HTTP COUNT {arm}" + ); + assert_eq!(fx.ws_count(&filter).await, closed("c"), "WS COUNT {arm}"); + } + let (status, body) = fx.http("/query", &fx.search_filter()).await; + assert_eq!( + (status, body["error"].as_str()), + ( + StatusCode::SERVICE_UNAVAILABLE, + Some(super::super::QUERY_TIMED_OUT) + ), + "HTTP search hydrate" + ); + assert_eq!(fx.ws_search().await, closed("s"), "WS search hydrate"); + locker.rollback().await.expect("unlock"); + + // Ordinary-error controls: `events` gone on both pools → 42P01 on the + // replica, writer re-run, 42P01 again. Not a timeout. + for pool in [&fx.writer, &fx.replica] { + sqlx::query("ALTER TABLE events RENAME TO events_gone") + .execute(pool) + .await + .expect("rename events"); + } + let (arm, filter) = fx.count_cases().swap_remove(0); + let (status, body) = fx.http("/count", &filter).await; + assert_eq!( + (status, body["error"].as_str()), + ( + StatusCode::INTERNAL_SERVER_ERROR, + Some("internal server error") + ), + "HTTP COUNT {arm} ordinary error" + ); + let frame = fx.ws_count(&filter).await; + assert!( + frame.starts_with(r#"["CLOSED","c","error: "#) && !frame.contains("query timed out"), + "WS COUNT {arm} ordinary error: {frame}" + ); + + fx.drop().await; + } + + /// A search REQ reusing a live subscription's ID retires it (NIP-01 + /// replacement) before its hydrate is cancelled, so the timeout CLOSED + /// leaves nothing registered under the ID. + #[tokio::test] + #[ignore = "requires Postgres"] + async fn search_reusing_live_id_retires_it_before_timeout_closed() { + use crate::handlers::req::handle_req; + let fx = cancel_fixture().await; + let (conn, mut rx) = fx.ws_conn(); + let frames = |rx: &mut tokio::sync::mpsc::Receiver| { + std::iter::from_fn(|| rx.try_recv().ok()) + .map(|msg| match msg { + axum::extract::ws::Message::Text(t) => t.to_string(), + other => panic!("expected text frame, got {other:?}"), + }) + .collect::>() + }; + let channel: uuid::Uuid = fx.channel.parse().expect("channel uuid"); + let topic = buzz_pubsub::EventTopic::Channel(channel); + let tenant = TenantContext::resolved(fx.community, fx.host.clone()); + let live: nostr::Filter = + serde_json::from_value(serde_json::json!({"kinds": [9], "#h": [&fx.channel]})) + .expect("live filter"); + handle_req( + "x".into(), + vec![live], + vec![None], + conn.clone(), + fx.state.clone(), + ) + .await; + assert!( + frames(&mut rx) + .last() + .is_some_and(|f| f == r#"["EOSE","x"]"#), + "live x served" + ); + assert!(conn.subscriptions.lock().await.contains_key("x")); + assert!(fx + .state + .sub_registry + .get_filters(conn.conn_id, "x") + .is_some()); + assert_eq!(fx.state.pubsub.topic_refcount(&tenant, topic).await, 1); + + let mut locker = fx.replica.begin().await.expect("begin locker"); + sqlx::query("LOCK TABLE events IN ACCESS EXCLUSIVE MODE") + .execute(&mut *locker) + .await + .expect("lock replica events"); + let search: nostr::Filter = + serde_json::from_value(fx.search_filter()).expect("search filter"); + let live_owner = *conn.subscriptions.lock().await.get("x").expect("x owned"); + let task = tokio::spawn(handle_req( + "x".into(), + vec![search], + vec![None], + conn.clone(), + fx.state.clone(), + )); + // Once search has claimed `x` its hydrate blocks on the lock. The old + // live fan-out must already be retired then, not only at final cleanup. + while conn.subscriptions.lock().await.get("x") == Some(&live_owner) { + tokio::task::yield_now().await; + } + assert!( + fx.state + .sub_registry + .get_filters(conn.conn_id, "x") + .is_none(), + "accepting search must retire live fan-out" + ); + assert_eq!(fx.state.pubsub.topic_refcount(&tenant, topic).await, 0); + task.await.expect("search task"); + locker.rollback().await.expect("unlock"); + + assert_eq!( + frames(&mut rx), + vec![format!( + r#"["CLOSED","x","{}"]"#, + crate::handlers::req::QUERY_TIMED_OUT_CLOSED + )] + ); + assert!(conn.subscriptions.lock().await.is_empty(), "conn map"); + assert!( + fx.state + .sub_registry + .get_filters(conn.conn_id, "x") + .is_none(), + "fan-out registration must be retired" + ); + assert_eq!(fx.state.pubsub.topic_refcount(&tenant, topic).await, 0); + + drop(conn); + fx.drop().await; + } } diff --git a/crates/buzz-relay/src/api/mod.rs b/crates/buzz-relay/src/api/mod.rs index c84192a6e6..460f7f70b8 100644 --- a/crates/buzz-relay/src/api/mod.rs +++ b/crates/buzz-relay/src/api/mod.rs @@ -27,6 +27,24 @@ pub(crate) fn internal_error(msg: &str) -> (StatusCode, Json) api_error(StatusCode::INTERNAL_SERVER_ERROR, "internal server error") } +/// Stable client-visible body for a read cancelled by its server-side +/// statement deadline. Clients match this string to skip retrying: a retry +/// would re-run the same expensive query. +pub(crate) const QUERY_TIMED_OUT: &str = "query timed out"; + +/// Map a DB read failure: a statement-deadline cancel becomes a distinct +/// 503 `query timed out`; anything else stays a generic 500. +pub(crate) fn db_read_error( + context: &str, + e: &buzz_db::DbError, +) -> (StatusCode, Json) { + if e.is_statement_cancelled() { + tracing::warn!("{context}: {e}"); + return api_error(StatusCode::SERVICE_UNAVAILABLE, QUERY_TIMED_OUT); + } + internal_error(&format!("{context}: {e}")) +} + #[allow(dead_code)] pub(crate) fn not_found(msg: &str) -> (StatusCode, Json) { api_error(StatusCode::NOT_FOUND, msg) @@ -406,6 +424,46 @@ pub mod relay_members { } } +#[cfg(test)] +mod db_read_error_tests { + use super::*; + + #[test] + fn non_cancel_db_error_stays_generic_500() { + let (status, body) = db_read_error("ctx", &buzz_db::DbError::NotFound("x".into())); + assert_eq!(status, StatusCode::INTERNAL_SERVER_ERROR); + assert_eq!(body.0["error"], "internal server error"); + } +} + +#[cfg(test)] +mod postgres_tests { + use super::*; + + #[tokio::test] + #[ignore = "requires Postgres"] + async fn statement_timeout_maps_to_distinct_503() { + let pool = sqlx::PgPool::connect(&crate::test_support::database_url()) + .await + .expect("connect to test DB"); + let mut tx = pool.begin().await.expect("begin"); + sqlx::query("SET LOCAL statement_timeout = '10ms'") + .execute(&mut *tx) + .await + .expect("set timeout"); + let err: buzz_db::DbError = sqlx::query("SELECT pg_sleep(1)") + .execute(&mut *tx) + .await + .expect_err("statement must be cancelled") + .into(); + assert!(err.is_statement_cancelled()); + + let (status, body) = db_read_error("ctx", &err); + assert_eq!(status, StatusCode::SERVICE_UNAVAILABLE); + assert_eq!(body.0["error"], QUERY_TIMED_OUT); + } +} + // ── parse_query_or_400 regression tests ────────────────────────────────────── #[cfg(test)] diff --git a/crates/buzz-relay/src/connection.rs b/crates/buzz-relay/src/connection.rs index 12a450861e..63060fe0be 100644 --- a/crates/buzz-relay/src/connection.rs +++ b/crates/buzz-relay/src/connection.rs @@ -16,7 +16,6 @@ use uuid::Uuid; use buzz_auth::{generate_challenge, AuthContext}; use buzz_core::tenant::TenantContext; -use nostr::Filter; use crate::handlers; use crate::metrics::AuthOutcome; @@ -34,8 +33,9 @@ const AUTH_TIMEOUT: Duration = Duration::from_secs(5); /// This stays well inside the process-wide 30-second hard drain. const WS_TERMINAL_FLUSH_TIMEOUT: Duration = Duration::from_secs(1); -/// Shared mutable subscription map for a single WebSocket connection. -pub(crate) type ConnectionSubscriptions = Arc>>>; +/// Shared mutable subscription map for a single WebSocket connection: sub ID → +/// owner token of the request that currently holds it (see `close::next_owner`). +pub(crate) type ConnectionSubscriptions = Arc>>; /// Request for the writer to flush a restart close and report the result. pub(crate) struct RestartClose { @@ -447,20 +447,7 @@ async fn handle_active_connection( let _ = auth_timeout_task.await; let _ = auth_cancel_task.await; - for removed in state.sub_registry.remove_connection(conn.conn_id) { - if removed.scope.is_global() { - state - .pubsub - .release_topic(&conn.tenant, buzz_pubsub::EventTopic::Global) - .await; - } - for &channel_id in removed.scope.channel_ids() { - state - .pubsub - .release_topic(&conn.tenant, buzz_pubsub::EventTopic::Channel(channel_id)) - .await; - } - } + crate::handlers::close::release_connection_subscriptions(&conn, &state).await; state.conn_manager.deregister(conn.conn_id); if let Some(auth_ctx) = authenticated { let remaining = state.conn_manager.connection_ids_for_pubkey_in_community( diff --git a/crates/buzz-relay/src/handlers/close.rs b/crates/buzz-relay/src/handlers/close.rs index 86f3d0da79..0fdb4dd167 100644 --- a/crates/buzz-relay/src/handlers/close.rs +++ b/crates/buzz-relay/src/handlers/close.rs @@ -1,35 +1,137 @@ +use std::collections::HashMap; +use std::sync::atomic::{AtomicU64, Ordering}; use std::sync::Arc; +use buzz_core::tenant::TenantContext; +use buzz_pubsub::EventTopic; + use tracing::debug; use crate::connection::ConnectionState; use crate::protocol::RelayMessage; use crate::state::AppState; +use crate::subscription::SubscriptionScope; /// Handle a CLOSE command — remove the subscription and send CLOSED acknowledgement. pub async fn handle_close(sub_id: String, conn: Arc, state: Arc) { - let conn_id = conn.conn_id; + // Client CLOSE targets whatever currently holds the ID, so it is + // unconditional. Retiring before CLOSED means nothing is routed to this + // sub after the acknowledgement. + let mut subs = conn.subscriptions.lock().await; + retire_locked(&mut subs, &sub_id, &conn, &state).await; + conn.send(RelayMessage::closed(&sub_id, "")); + drop(subs); - conn.subscriptions.lock().await.remove(&sub_id); + debug!(conn_id = %conn.conn_id, sub_id = %sub_id, "Subscription closed"); +} - // Deregister from the fan-out index before sending CLOSED so no new - // messages are routed to this sub after the client's CLOSE is acknowledged. - if let Some(removed) = state.sub_registry.remove_subscription(conn_id, &sub_id) { - if removed.scope.is_global() { - state - .pubsub - .release_topic(&conn.tenant, buzz_pubsub::EventTopic::Global) - .await; - } - for &channel_id in removed.scope.channel_ids() { - state - .pubsub - .release_topic(&conn.tenant, buzz_pubsub::EventTopic::Channel(channel_id)) - .await; +/// Monotonic source of subscription owner tokens. Each REQ claims its sub ID +/// with a fresh token, so a superseded request can tell it no longer owns it. +static NEXT_OWNER: AtomicU64 = AtomicU64::new(1); + +pub(crate) fn next_owner() -> u64 { + NEXT_OWNER.fetch_add(1, Ordering::Relaxed) +} + +// Lifecycle lock: `conn.subscriptions` serializes every change to a +// connection's subscription state — map token, registry entry, topic +// retention, and the terminal CLOSED frame. Neither the registry nor pubsub +// takes it, so holding it across their awaits cannot invert lock order. + +/// Drop `sub_id` from the map, the fan-out index, and its topic retention. +/// The caller holds the lifecycle lock (`subs`). +pub(crate) async fn retire_locked( + subs: &mut HashMap, + sub_id: &str, + conn: &ConnectionState, + state: &AppState, +) { + subs.remove(sub_id); + if let Some(removed) = state.sub_registry.remove_subscription(conn.conn_id, sub_id) { + release_scope_topics(state, &conn.tenant, &removed.scope).await; + } +} + +/// Retire `sub_id` only if the request holding `owner` still owns it, then +/// send `closed` (if any) before releasing the lifecycle lock, so a replacing +/// REQ can never claim the ID between the teardown and its terminal frame. +/// Returns whether this request still owned the ID. A superseded request +/// touches nothing and says nothing. +pub(crate) async fn close_if_owner( + sub_id: &str, + owner: u64, + closed: Option<&str>, + conn: &ConnectionState, + state: &AppState, +) -> bool { + let mut subs = conn.subscriptions.lock().await; + if subs.get(sub_id) != Some(&owner) { + return false; + } + retire_locked(&mut subs, sub_id, conn, state).await; + #[cfg(test)] + test_seam::pause().await; + if let Some(reason) = closed { + if !conn.send(RelayMessage::closed(sub_id, reason)) { + // The outbound channel is full or closed: the terminal frame is + // lost. Cancel the connection so the subscription is not silently + // orphaned — the client will reconnect and resubscribe. + conn.cancel.cancel(); + } + } + true +} + +/// Final subscription cleanup for a closed connection. Its cancellation token +/// must already be cancelled: claims check it under the lifecycle lock, so no +/// detached REQ task can register after this runs. +pub(crate) async fn release_connection_subscriptions(conn: &ConnectionState, state: &AppState) { + debug_assert!(conn.cancel.is_cancelled()); + let mut subs = conn.subscriptions.lock().await; + subs.clear(); + for removed in state.sub_registry.remove_connection(conn.conn_id) { + release_scope_topics(state, &conn.tenant, &removed.scope).await; + } +} + +/// Release the pubsub topics a subscription scope retained. +pub(crate) async fn release_scope_topics( + state: &AppState, + tenant: &TenantContext, + scope: &SubscriptionScope, +) { + if scope.is_global() { + state.pubsub.release_topic(tenant, EventTopic::Global).await; + } + for &channel_id in scope.channel_ids() { + state + .pubsub + .release_topic(tenant, EventTopic::Channel(channel_id)) + .await; + } +} + +/// Test-only pause point inside `close_if_owner`, between teardown and the +/// terminal frame, scoped to one task so parallel tests don't interfere. +#[cfg(test)] +pub(crate) mod test_seam { + use std::sync::Arc; + use tokio::sync::Notify; + + #[derive(Default)] + pub(crate) struct Pause { + pub(crate) reached: Notify, + pub(crate) resume: Notify, + } + + tokio::task_local! { + pub(crate) static PAUSE: Arc; + } + + pub(super) async fn pause() { + if let Ok(pause) = PAUSE.try_with(Arc::clone) { + pause.reached.notify_one(); + pause.resume.notified().await; } } - - conn.send(RelayMessage::closed(&sub_id, "")); - - debug!(conn_id = %conn_id, sub_id = %sub_id, "Subscription closed"); } diff --git a/crates/buzz-relay/src/handlers/count.rs b/crates/buzz-relay/src/handlers/count.rs index 5ea30b238b..50a77e42ef 100644 --- a/crates/buzz-relay/src/handlers/count.rs +++ b/crates/buzz-relay/src/handlers/count.rs @@ -198,7 +198,10 @@ pub async fn handle_count( match state.db.count_events_routed("count_req", &query).await { Ok(n) => total += n as u64, Err(e) => { - conn.send(RelayMessage::closed(&sub_id, &format!("error: {e}"))); + conn.send(RelayMessage::closed( + &sub_id, + &super::req::db_read_closed_reason(&e), + )); return; } } @@ -232,7 +235,10 @@ pub async fn handle_count( } } Err(e) => { - conn.send(RelayMessage::closed(&sub_id, &format!("error: {e}"))); + conn.send(RelayMessage::closed( + &sub_id, + &super::req::db_read_closed_reason(&e), + )); return; } } @@ -272,7 +278,10 @@ pub async fn handle_count( match state.db.count_events_routed("count_req", &query).await { Ok(n) => total += n as u64, Err(e) => { - conn.send(RelayMessage::closed(&sub_id, &format!("error: {e}"))); + conn.send(RelayMessage::closed( + &sub_id, + &super::req::db_read_closed_reason(&e), + )); return; } } @@ -305,7 +314,10 @@ pub async fn handle_count( } } Err(e) => { - conn.send(RelayMessage::closed(&sub_id, &format!("error: {e}"))); + conn.send(RelayMessage::closed( + &sub_id, + &super::req::db_read_closed_reason(&e), + )); return; } } diff --git a/crates/buzz-relay/src/handlers/req.rs b/crates/buzz-relay/src/handlers/req.rs index 97d252cb7e..a428f1e821 100644 --- a/crates/buzz-relay/src/handlers/req.rs +++ b/crates/buzz-relay/src/handlers/req.rs @@ -267,8 +267,12 @@ pub async fn handle_req( )); return; } + let Some(owner) = claim_search_subscription(&sub_id, &conn, &state).await else { + return; + }; handle_search_req( &sub_id, + owner, &filters, &accessible_channels, token_channel_ids.is_none(), @@ -279,47 +283,22 @@ pub async fn handle_req( trace_state.as_ref(), ) .await; + // One-shot: drop the claim unless a newer REQ already took the ID. + super::close::close_if_owner(&sub_id, owner, None, &conn, &state).await; return; } - { - let mut subs = conn.subscriptions.lock().await; - subs.insert(sub_id.clone(), filters.clone()); - } - - let replaced = if let Some(channel_ids) = authorized_requested_channels.as_ref() { - state.sub_registry.register_channels_scoped( - conn.tenant.community(), - conn_id, - sub_id.clone(), - filters.clone(), - channel_ids.clone(), - ) - } else { - state.sub_registry.register_scoped( - conn.tenant.community(), - conn_id, - sub_id.clone(), - filters.clone(), - None, - ) + let Some(owner) = claim_live_subscription( + &sub_id, + &filters, + authorized_requested_channels.as_deref(), + &conn, + &state, + ) + .await + else { + return; }; - if let Some(replaced) = replaced { - release_subscription_topics(&state, &conn.tenant, &replaced.scope).await; - } - if let Some(channel_ids) = authorized_requested_channels.as_ref() { - for &channel_id in channel_ids { - state - .pubsub - .retain_topic(&conn.tenant, EventTopic::Channel(channel_id)) - .await; - } - } else { - state - .pubsub - .retain_topic(&conn.tenant, EventTopic::Global) - .await; - } debug!(conn_id = %conn_id, sub_id = %sub_id, "Subscription registered"); @@ -396,7 +375,11 @@ pub async fn handle_req( Ok(evs) => evs, Err(e) => { warn!(conn_id = %conn_id, sub_id = %sub_id, "Historical query failed: {e}"); - conn.send(RelayMessage::eose(&sub_id)); + if e.is_statement_cancelled() { + close_timed_out_subscription(&sub_id, owner, &conn, &state).await; + } else { + conn.send(RelayMessage::eose(&sub_id)); + } return; } }; @@ -597,6 +580,7 @@ pub(crate) fn build_search_channel_scope_filter( #[allow(clippy::too_many_arguments)] async fn handle_search_req( sub_id: &str, + owner: u64, filters: &[Filter], accessible_channels: &[uuid::Uuid], include_global: bool, @@ -724,6 +708,12 @@ async fn handle_search_req( .await { Ok(evs) => evs, + Err(e) if e.is_statement_cancelled() => { + // CLOSED (not EOSE) keeps partial results from reading as complete. + warn!(sub_id = %sub_id, "NIP-50 batch fetch timed out: {e}"); + close_timed_out_subscription(sub_id, owner, conn, state).await; + return; + } Err(e) => { warn!(sub_id = %sub_id, "NIP-50 batch fetch failed: {e}"); break; @@ -1269,21 +1259,107 @@ async fn handle_huddle_liveness_req( conn.send(RelayMessage::eose(sub_id)); } -async fn release_subscription_topics( +/// Claim `sub_id` for a live REQ under the lifecycle lock: record a fresh +/// owner token, register for fan-out (replacing any same-ID entry), retain its +/// topics, and release the replaced scope's. Returns the owner token, or +/// `None` once the connection is closing — the caller then exits silently. +async fn claim_live_subscription( + sub_id: &str, + filters: &[Filter], + channel_ids: Option<&[uuid::Uuid]>, + conn: &ConnectionState, state: &AppState, - tenant: &TenantContext, - scope: &crate::subscription::SubscriptionScope, -) { - if scope.is_global() { - state.pubsub.release_topic(tenant, EventTopic::Global).await; - } else { - for &channel_id in scope.channel_ids() { +) -> Option { + let mut subs = conn.subscriptions.lock().await; + if conn.cancel.is_cancelled() { + return None; + } + let owner = super::close::next_owner(); + subs.insert(sub_id.to_string(), owner); + let community = conn.tenant.community(); + let replaced = match channel_ids { + Some(ids) => state.sub_registry.register_channels_scoped( + community, + conn.conn_id, + sub_id.to_string(), + filters.to_vec(), + ids.to_vec(), + ), + None => state.sub_registry.register_scoped( + community, + conn.conn_id, + sub_id.to_string(), + filters.to_vec(), + None, + ), + }; + match channel_ids { + Some(ids) => { + for &channel_id in ids { + state + .pubsub + .retain_topic(&conn.tenant, EventTopic::Channel(channel_id)) + .await; + } + } + None => { state .pubsub - .release_topic(tenant, EventTopic::Channel(channel_id)) + .retain_topic(&conn.tenant, EventTopic::Global) .await; } } + if let Some(replaced) = replaced { + super::close::release_scope_topics(state, &conn.tenant, &replaced.scope).await; + } + Some(owner) +} + +/// Claim `sub_id` for a one-shot search REQ under the lifecycle lock. +/// Accepting it retires whatever holds the ID (NIP-01 replacement), even +/// though search never registers for fan-out. `None` once the connection is +/// closing. +async fn claim_search_subscription( + sub_id: &str, + conn: &ConnectionState, + state: &AppState, +) -> Option { + let mut subs = conn.subscriptions.lock().await; + if conn.cancel.is_cancelled() { + return None; + } + super::close::retire_locked(&mut subs, sub_id, conn, state).await; + let owner = super::close::next_owner(); + subs.insert(sub_id.to_string(), owner); + Some(owner) +} + +/// A read hit the server statement deadline. Sends `CLOSED` rather than `EOSE` +/// so clients don't treat the empty result as complete. CLOSED means the relay +/// dropped the sub (NIP-01) and clients won't `CLOSE` it, so it is retired in +/// the same lifecycle-lock critical section. A request a newer same-ID REQ +/// superseded owns nothing and says nothing. +async fn close_timed_out_subscription( + sub_id: &str, + owner: u64, + conn: &ConnectionState, + state: &AppState, +) { + super::close::close_if_owner(sub_id, owner, Some(QUERY_TIMED_OUT_CLOSED), conn, state).await; +} + +/// Stable CLOSED reason for a read cancelled by its server statement deadline. +/// Clients match it to skip retrying the same expensive query. +pub(crate) const QUERY_TIMED_OUT_CLOSED: &str = "error: query timed out"; + +/// CLOSED reason for a failed one-shot DB read (COUNT): a statement cancel gets +/// the stable timeout reason; anything else keeps the raw error. +pub(crate) fn db_read_closed_reason(e: &buzz_db::DbError) -> String { + if e.is_statement_cancelled() { + QUERY_TIMED_OUT_CLOSED.to_string() + } else { + format!("error: {e}") + } } fn extract_channel_id_from_filters(filters: &[Filter]) -> Option { @@ -1554,6 +1630,491 @@ mod tests { use super::*; use nostr::{Alphabet, Filter, SingleLetterTag}; + fn lifecycle_conn() -> ( + ConnectionState, + tokio::sync::mpsc::Receiver, + ) { + use std::sync::atomic::AtomicU8; + let (send_tx, send_rx) = tokio::sync::mpsc::channel(8); + let (ctrl_tx, _ctrl_rx) = tokio::sync::mpsc::channel(1); + let community = buzz_core::tenant::CommunityId::from_uuid(uuid::Uuid::new_v4()); + let conn = ConnectionState { + conn_id: uuid::Uuid::new_v4(), + tenant: buzz_core::tenant::TenantContext::resolved(community, "t.local".to_string()), + remote_addr: "127.0.0.1:1234".parse().expect("addr"), + auth_state: std::sync::Mutex::new(AuthState::Failed), + subscriptions: Arc::new(tokio::sync::Mutex::new(std::collections::HashMap::new())), + send_tx, + ctrl_tx, + cancel: tokio_util::sync::CancellationToken::new(), + backpressure_count: Arc::new(AtomicU8::new(0)), + grace_limit: 3, + }; + (conn, send_rx) + } + + fn text_filters() -> Vec { + vec![Filter::new().kind(nostr::Kind::TextNote)] + } + + fn registered(state: &AppState, conn: &ConnectionState, sub_id: &str) -> bool { + state + .sub_registry + .get_filters(conn.conn_id, sub_id) + .is_some() + } + + fn closed_frames( + rx: &mut tokio::sync::mpsc::Receiver, + ) -> Vec { + std::iter::from_fn(|| rx.try_recv().ok()) + .map(|msg| match msg { + axum::extract::ws::Message::Text(t) => t.to_string(), + other => panic!("expected text frame, got {other:?}"), + }) + .collect() + } + + #[tokio::test] + async fn timed_out_historical_read_deregisters_before_closed() { + let state = crate::state::tests::test_state().await; + let (conn, mut send_rx) = lifecycle_conn(); + let channel = uuid::Uuid::new_v4(); + let topic = EventTopic::Channel(channel); + let owner = + claim_live_subscription("thread", &text_filters(), Some(&[channel]), &conn, &state) + .await + .expect("claim"); + assert_eq!(state.pubsub.topic_refcount(&conn.tenant, topic).await, 1); + + close_timed_out_subscription("thread", owner, &conn, &state).await; + + assert!(conn.subscriptions.lock().await.is_empty()); + assert!( + !registered(&state, &conn, "thread"), + "fan-out registration must be gone" + ); + assert_eq!( + state.pubsub.topic_refcount(&conn.tenant, topic).await, + 0, + "retained topic must be released" + ); + assert_eq!( + closed_frames(&mut send_rx), + vec![format!(r#"["CLOSED","thread","{QUERY_TIMED_OUT_CLOSED}"]"#)] + ); + } + + /// A superseded REQ's late timeout must not tear down, or send a terminal + /// CLOSED for, the same-ID replacement that now owns the ID. + #[tokio::test] + async fn superseded_timeout_leaves_replacement_intact() { + let state = crate::state::tests::test_state().await; + let (conn, mut send_rx) = lifecycle_conn(); + let (old_channel, new_channel) = (uuid::Uuid::new_v4(), uuid::Uuid::new_v4()); + let (old_topic, new_topic) = ( + EventTopic::Channel(old_channel), + EventTopic::Channel(new_channel), + ); + let old = + claim_live_subscription("x", &text_filters(), Some(&[old_channel]), &conn, &state) + .await + .expect("claim"); + let new = + claim_live_subscription("x", &text_filters(), Some(&[new_channel]), &conn, &state) + .await + .expect("claim"); + assert_eq!( + state.pubsub.topic_refcount(&conn.tenant, old_topic).await, + 0 + ); + + close_timed_out_subscription("x", old, &conn, &state).await; + + assert_eq!(conn.subscriptions.lock().await.get("x"), Some(&new)); + assert!( + registered(&state, &conn, "x"), + "replacement must stay registered" + ); + assert_eq!( + state.pubsub.topic_refcount(&conn.tenant, new_topic).await, + 1, + "replacement topic must stay retained" + ); + assert!( + closed_frames(&mut send_rx).is_empty(), + "superseded request must say nothing" + ); + } + + /// Accepting a search REQ retires the live subscription holding its ID, and + /// a search that a newer live REQ supersedes cannot close that REQ. + #[tokio::test] + async fn search_claim_retires_live_and_yields_to_replacement() { + let state = crate::state::tests::test_state().await; + let (conn, mut send_rx) = lifecycle_conn(); + let channel = uuid::Uuid::new_v4(); + let topic = EventTopic::Channel(channel); + claim_live_subscription("x", &text_filters(), Some(&[channel]), &conn, &state) + .await + .expect("claim"); + + let search = claim_search_subscription("x", &conn, &state) + .await + .expect("claim"); + assert!( + !registered(&state, &conn, "x"), + "search must retire live fan-out" + ); + assert_eq!(state.pubsub.topic_refcount(&conn.tenant, topic).await, 0); + + let live = claim_live_subscription("x", &text_filters(), Some(&[channel]), &conn, &state) + .await + .expect("claim"); + close_timed_out_subscription("x", search, &conn, &state).await; + + assert_eq!(conn.subscriptions.lock().await.get("x"), Some(&live)); + assert!(registered(&state, &conn, "x")); + assert_eq!(state.pubsub.topic_refcount(&conn.tenant, topic).await, 1); + assert!(closed_frames(&mut send_rx).is_empty()); + } + + /// Concurrent same-ID claims and stale teardowns: whichever claim lands + /// last owns the ID, and every stale teardown is a silent no-op. + #[tokio::test] + async fn concurrent_claims_and_stale_teardowns_keep_the_last_owner() { + let state = crate::state::tests::test_state().await; + let (conn, mut send_rx) = lifecycle_conn(); + let conn = Arc::new(conn); + let channel = uuid::Uuid::new_v4(); + let topic = EventTopic::Channel(channel); + let stale = claim_live_subscription("x", &text_filters(), Some(&[channel]), &conn, &state) + .await + .expect("claim"); + + let tasks = (0..16).map(|i| { + let (conn, state) = (Arc::clone(&conn), Arc::clone(&state)); + tokio::spawn(async move { + if i % 2 == 0 { + claim_live_subscription("x", &text_filters(), Some(&[channel]), &conn, &state) + .await + .expect("claim"); + } else { + close_timed_out_subscription("x", stale, &conn, &state).await; + } + }) + }); + for task in tasks.collect::>() { + task.await.expect("task"); + } + + let owner = *conn.subscriptions.lock().await.get("x").expect("x owned"); + assert_ne!(owner, stale); + assert!(registered(&state, &conn, "x")); + assert_eq!(state.pubsub.topic_refcount(&conn.tenant, topic).await, 1); + close_timed_out_subscription("x", owner, &conn, &state).await; + assert_eq!(state.pubsub.topic_refcount(&conn.tenant, topic).await, 0); + assert_eq!( + closed_frames(&mut send_rx), + vec![format!(r#"["CLOSED","x","{QUERY_TIMED_OUT_CLOSED}"]"#)], + "only the final owner's teardown may close" + ); + } + + fn subscribed(state: &AppState, conn: &ConnectionState, channel: uuid::Uuid) -> bool { + state + .sub_registry + .channel_subscriber_conns_scoped(conn.tenant.community(), channel) + .contains(&conn.conn_id) + } + + /// Poll `fut` exactly once and require it to park. A contender for a held + /// tokio mutex enqueues its waiter and returns `Pending` on that poll, so + /// this proves it reached its lock attempt without relying on scheduling. + async fn assert_parked(fut: &mut F, what: &str) { + let parked = std::future::poll_fn(|cx| { + std::task::Poll::Ready(std::pin::Pin::new(&mut *fut).poll(cx).is_pending()) + }) + .await; + assert!(parked, "{what} must be waiting on the lifecycle lock"); + } + + /// The owner's teardown and its terminal CLOSED are one critical section: + /// a replacement claiming meanwhile waits, so it can never be the target of + /// the old request's CLOSED. + #[tokio::test] + async fn timeout_closed_is_emitted_before_a_replacement_can_claim() { + use super::super::close::test_seam::{Pause, PAUSE}; + let state = crate::state::tests::test_state().await; + let (conn, mut send_rx) = lifecycle_conn(); + let conn = Arc::new(conn); + let (a, b) = (uuid::Uuid::new_v4(), uuid::Uuid::new_v4()); + let old = claim_live_subscription("x", &text_filters(), Some(&[a]), &conn, &state) + .await + .expect("claim"); + + let pause = Arc::new(Pause::default()); + let teardown = tokio::spawn(PAUSE.scope(Arc::clone(&pause), { + let (conn, state) = (Arc::clone(&conn), Arc::clone(&state)); + async move { close_timed_out_subscription("x", old, &conn, &state).await } + })); + pause.reached.notified().await; + let (filters, b_scope) = (text_filters(), [b]); + let mut replacement = Box::pin(claim_live_subscription( + "x", + &filters, + Some(&b_scope), + &conn, + &state, + )); + assert_parked(&mut replacement, "replacement").await; + assert!( + !subscribed(&state, &conn, b), + "replacement must not claim between teardown and CLOSED" + ); + assert!(closed_frames(&mut send_rx).is_empty()); + + pause.resume.notify_one(); + teardown.await.expect("teardown"); + let new = replacement.await.expect("claim"); + + assert_eq!( + closed_frames(&mut send_rx), + vec![format!(r#"["CLOSED","x","{QUERY_TIMED_OUT_CLOSED}"]"#)] + ); + assert_eq!(conn.subscriptions.lock().await.get("x"), Some(&new)); + assert!(subscribed(&state, &conn, b) && !subscribed(&state, &conn, a)); + let refcount = |c| { + state + .pubsub + .topic_refcount(&conn.tenant, EventTopic::Channel(c)) + }; + assert_eq!((refcount(a).await, refcount(b).await), (0, 1)); + } + + /// Revoke selects and removes registry entries under the lifecycle lock, so + /// a same-ID replacement queued behind it keeps its token, scope and topic. + #[tokio::test] + async fn revoke_then_replacement_keeps_replacement_whole() { + let state = crate::state::tests::test_state().await; + let (conn, mut send_rx) = lifecycle_conn(); + let conn = Arc::new(conn); + state.conn_manager.register( + conn.conn_id, + conn.send_tx.clone(), + conn.ctrl_tx.clone(), + None, + conn.cancel.clone(), + conn.tenant.community(), + Arc::clone(&conn.backpressure_count), + Arc::clone(&conn.subscriptions), + 3, + ); + let (a, b) = (uuid::Uuid::new_v4(), uuid::Uuid::new_v4()); + claim_live_subscription("x", &text_filters(), Some(&[a]), &conn, &state) + .await + .expect("claim"); + + let guard = conn.subscriptions.lock().await; + let mut revoke = Box::pin( + crate::handlers::side_effects::evict_conn_channel_subscriptions( + &conn.tenant, + &state, + a, + conn.conn_id, + ), + ); + assert_parked(&mut revoke, "revoke").await; + let (filters, b_scope) = (text_filters(), [b]); + let mut replacement = Box::pin(claim_live_subscription( + "x", + &filters, + Some(&b_scope), + &conn, + &state, + )); + assert_parked(&mut replacement, "replacement").await; + assert!( + subscribed(&state, &conn, a), + "revoke must not touch the registry before taking the lifecycle lock" + ); + drop(guard); + // The tokio mutex is FIFO: revoke queued first, so it runs first. + revoke.await; + let new = replacement.await.expect("claim"); + + assert_eq!(conn.subscriptions.lock().await.get("x"), Some(&new)); + assert!(subscribed(&state, &conn, b) && !subscribed(&state, &conn, a)); + let refcount = |c| { + state + .pubsub + .topic_refcount(&conn.tenant, EventTopic::Channel(c)) + }; + assert_eq!((refcount(a).await, refcount(b).await), (0, 1)); + assert_eq!( + closed_frames(&mut send_rx), + vec![r#"["CLOSED","x","restricted: channel access revoked"]"#.to_string()] + ); + state.conn_manager.deregister(conn.conn_id); + } + + /// Connection cleanup fences later claims: a detached REQ task resuming + /// after it gets `None` and leaves nothing behind. + #[tokio::test] + async fn claims_after_connection_cleanup_are_refused() { + let state = crate::state::tests::test_state().await; + let (conn, mut send_rx) = lifecycle_conn(); + let channel = uuid::Uuid::new_v4(); + let topic = EventTopic::Channel(channel); + claim_live_subscription("live", &text_filters(), Some(&[channel]), &conn, &state) + .await + .expect("claim"); + + conn.cancel.cancel(); + super::super::close::release_connection_subscriptions(&conn, &state).await; + let late_live = + claim_live_subscription("late", &text_filters(), Some(&[channel]), &conn, &state).await; + let late_search = claim_search_subscription("search", &conn, &state).await; + + assert_eq!((late_live, late_search), (None, None)); + assert!(conn.subscriptions.lock().await.is_empty()); + for sub in ["live", "late", "search"] { + assert!( + !registered(&state, &conn, sub), + "{sub} must not be registered" + ); + } + assert_eq!(state.pubsub.topic_refcount(&conn.tenant, topic).await, 0); + assert!(closed_frames(&mut send_rx).is_empty()); + } + + /// A terminal CLOSED that fails to enqueue after retirement cancels the + /// connection, so the subscription is never silently orphaned on a + /// congested connection. + /// + /// Regression for P2-2: before this fix, a `false` from `conn.send` was + /// silently ignored after retirement, leaving the subscription retired but + /// the connection alive without a CLOSED delivered to the client. + #[tokio::test] + async fn dropped_terminal_frame_cancels_connection() { + use std::sync::atomic::AtomicU8; + let state = crate::state::tests::test_state().await; + // Capacity-1 channel: one dummy message fills it, so the CLOSED + // `try_send` returns Full (below the grace_limit=3 auto-cancel) and + // the fix's explicit cancel must fire. + let (send_tx, mut send_rx) = tokio::sync::mpsc::channel(1); + let (ctrl_tx, _ctrl_rx) = tokio::sync::mpsc::channel(1); + let community = buzz_core::tenant::CommunityId::from_uuid(uuid::Uuid::new_v4()); + let conn = Arc::new(ConnectionState { + conn_id: uuid::Uuid::new_v4(), + tenant: buzz_core::tenant::TenantContext::resolved(community, "t.local".to_string()), + remote_addr: "127.0.0.1:1234".parse().expect("addr"), + auth_state: std::sync::Mutex::new(AuthState::Failed), + subscriptions: Arc::new(tokio::sync::Mutex::new(std::collections::HashMap::new())), + send_tx, + ctrl_tx, + cancel: tokio_util::sync::CancellationToken::new(), + backpressure_count: Arc::new(AtomicU8::new(0)), + grace_limit: 3, + }); + + // Claim, then fill the send buffer so the next `send` returns false. + let owner = claim_live_subscription("x", &text_filters(), None, &conn, &state) + .await + .expect("claim"); + // Occupy the one slot so try_send returns Full on the CLOSED. + send_rx.try_recv().ok(); // drain any prior messages + let _ = conn.send_tx.try_send(axum::extract::ws::Message::Text( + "filler".to_string().into(), + )); + assert!(!conn.cancel.is_cancelled(), "must not be cancelled yet"); + + // `close_timed_out_subscription` retires the sub and tries to send CLOSED. + // With the buffer full the frame is dropped and the fix must cancel. + close_timed_out_subscription("x", owner, &conn, &state).await; + + assert!( + conn.cancel.is_cancelled(), + "connection must be cancelled when the terminal frame is dropped" + ); + // The subscription is still retired — the map is empty. + assert!(conn.subscriptions.lock().await.is_empty()); + assert!(!registered(&state, &conn, "x")); + } + + /// A revoke `CLOSED restricted` that fails to enqueue after the map remove + /// cancels the connection, same as the timeout path. + /// + /// Regression for P2-2 (revoke branch): before this fix, a `false` from + /// `send_to` in `evict_conn_channel_subscriptions` was silently ignored + /// after retirement, leaving the subscription orphaned on a congested + /// connection. + #[tokio::test] + async fn revoke_dropped_terminal_frame_cancels_connection() { + use std::sync::atomic::AtomicU8; + let state = crate::state::tests::test_state().await; + // Capacity-1 channel: one dummy message fills it so the CLOSED + // restricted `try_send` returns Full (below grace_limit=3) and the + // fix's explicit cancel_conn must fire. + let (send_tx, mut send_rx) = tokio::sync::mpsc::channel(1); + let (ctrl_tx, _ctrl_rx) = tokio::sync::mpsc::channel(1); + let community = buzz_core::tenant::CommunityId::from_uuid(uuid::Uuid::new_v4()); + let conn = Arc::new(ConnectionState { + conn_id: uuid::Uuid::new_v4(), + tenant: buzz_core::tenant::TenantContext::resolved(community, "t.local".to_string()), + remote_addr: "127.0.0.1:1234".parse().expect("addr"), + auth_state: std::sync::Mutex::new(AuthState::Failed), + subscriptions: Arc::new(tokio::sync::Mutex::new(std::collections::HashMap::new())), + send_tx: send_tx.clone(), + ctrl_tx, + cancel: tokio_util::sync::CancellationToken::new(), + backpressure_count: Arc::new(AtomicU8::new(0)), + grace_limit: 3, + }); + // Register in conn_manager so evict_conn_channel_subscriptions can + // find the connection for cancel_conn. + state.conn_manager.register( + conn.conn_id, + send_tx, + conn.ctrl_tx.clone(), + None, + conn.cancel.clone(), + conn.tenant.community(), + Arc::clone(&conn.backpressure_count), + Arc::clone(&conn.subscriptions), + 3, + ); + + let channel = uuid::Uuid::new_v4(); + claim_live_subscription("x", &text_filters(), Some(&[channel]), &conn, &state) + .await + .expect("claim"); + + // Fill the one send slot so the CLOSED restricted try_send returns Full. + send_rx.try_recv().ok(); // drain any earlier messages + let _ = conn.send_tx.try_send(axum::extract::ws::Message::Text( + "filler".to_string().into(), + )); + assert!(!conn.cancel.is_cancelled(), "must not be cancelled yet"); + + crate::handlers::side_effects::evict_conn_channel_subscriptions( + &conn.tenant, + &state, + channel, + conn.conn_id, + ) + .await; + + assert!( + conn.cancel.is_cancelled(), + "connection must be cancelled when the revoke terminal frame is dropped" + ); + assert!(conn.subscriptions.lock().await.is_empty()); + assert!(!subscribed(&state, &conn, channel)); + + state.conn_manager.deregister(conn.conn_id); + } + #[test] fn huddle_liveness_filters_require_only_the_snapshot_kind() { let liveness = Filter::new().kind(nostr::Kind::Custom(KIND_HUDDLE_LIVENESS as u16)); diff --git a/crates/buzz-relay/src/handlers/side_effects.rs b/crates/buzz-relay/src/handlers/side_effects.rs index f63c174d96..c2131b1a55 100644 --- a/crates/buzz-relay/src/handlers/side_effects.rs +++ b/crates/buzz-relay/src/handlers/side_effects.rs @@ -231,41 +231,42 @@ async fn disable_departed_member_workflows( } /// Close every live channel-scoped subscription on `conn_id`, removing them from -/// the connection's local map and sending `CLOSED restricted` for each. -async fn evict_conn_channel_subscriptions( +/// the connection's local map and sending `CLOSED restricted` for each. Runs +/// under the connection's lifecycle lock so a concurrent same-ID claim is +/// either fully before (and revoked) or fully after (and untouched). +pub(crate) async fn evict_conn_channel_subscriptions( tenant: &TenantContext, state: &Arc, channel_id: Uuid, conn_id: uuid::Uuid, ) { + // No map means the connection already ran its final cleanup, which + // removed its registry entries under this same lock. + let Some(subscriptions) = state.conn_manager.subscriptions_for(conn_id) else { + return; + }; + let mut conn_subscriptions = subscriptions.lock().await; let removed = state.sub_registry.remove_channel_subscriptions_scoped( tenant.community(), conn_id, channel_id, ); - if removed.is_empty() { - return; - } - - if let Some(subscriptions) = state.conn_manager.subscriptions_for(conn_id) { - let mut conn_subscriptions = subscriptions.lock().await; - for update in &removed { - if update.removed { - conn_subscriptions.remove(&update.sub_id); - } - } - } - for update in removed { + // A multi-channel sub keeps its other channels (and its map token). state .pubsub .release_topic(tenant, buzz_pubsub::EventTopic::Channel(channel_id)) .await; if update.removed { - let _ = state.conn_manager.send_to( + conn_subscriptions.remove(&update.sub_id); + if !state.conn_manager.send_to( conn_id, RelayMessage::closed(&update.sub_id, "restricted: channel access revoked"), - ); + ) { + // Terminal frame lost — cancel so the subscription is not + // silently orphaned on a congested connection. + state.conn_manager.cancel_conn(conn_id); + } } } } diff --git a/crates/buzz-relay/src/state.rs b/crates/buzz-relay/src/state.rs index 0bcab5d63a..417e9bb763 100644 --- a/crates/buzz-relay/src/state.rs +++ b/crates/buzz-relay/src/state.rs @@ -459,6 +459,14 @@ impl ConnectionManager { .and_then(|entry| entry.authenticated_pubkey.read().ok()?.clone()) } + /// Cancel a single connection by ID. A no-op if the connection is not + /// registered (already deregistered or never known). + pub(crate) fn cancel_conn(&self, conn_id: Uuid) { + if let Some(entry) = self.connections.get(&conn_id) { + entry.cancel.cancel(); + } + } + /// Disconnect every live connection authenticated as `pubkey` **in /// `community`**, delivering a final `OK false` frame carrying `reason` /// before closing. diff --git a/desktop/src-tauri/src/native_relay_client_finite_tests.rs b/desktop/src-tauri/src/native_relay_client_finite_tests.rs index 913d17f5fd..7b236b98ac 100644 --- a/desktop/src-tauri/src/native_relay_client_finite_tests.rs +++ b/desktop/src-tauri/src/native_relay_client_finite_tests.rs @@ -101,6 +101,7 @@ async fn terminal_refusal_and_deadline_do_not_become_empty_success() { for message in [ "restricted: denied", "error: transient", + "error: query timed out", "rate-limited: quota exceeded; retry in 10s", "rate-limited: quota exceeded", "rate-limited: quota exceeded; retry in 18446744073709551615s", diff --git a/desktop/src-tauri/src/native_relay_client_tests.rs b/desktop/src-tauri/src/native_relay_client_tests.rs index f12a689449..ee284be518 100644 --- a/desktop/src-tauri/src/native_relay_client_tests.rs +++ b/desktop/src-tauri/src/native_relay_client_tests.rs @@ -328,6 +328,32 @@ async fn a_closed_subscription_reopens_without_a_desired_set_change() { session.shutdown(); } +/// A statement deadline on a persistent subscription is transient (archive +/// subs are `limit: 0` live tails), so it backs off and reopens rather than +/// latching terminal. Finite requests still fail on it; see +/// `native_relay_client_finite_tests.rs`. +#[tokio::test] +async fn a_deadline_closed_subscription_reopens_after_backoff() { + let (relay_url, mut frames, closed) = stub_relay().await; + let (session, _events) = start(relay_url, Keys::generate(), None).await; + + session.set_subscriptions(vec![probe_subscription()]).await; + assert_eq!(next_req(&mut frames, "the initial REQ").await, PROBE_ID); + settle().await; + + closed + .send(StubCommand::Closed( + PROBE_ID.into(), + "error: query timed out".into(), + )) + .await + .expect("stub relay accepts the closed command"); + + assert_eq!(next_req(&mut frames, "the reopened REQ").await, PROBE_ID); + + session.shutdown(); +} + /// A relay that rejects on policy must not be re-asked in a tight loop. #[tokio::test] async fn a_terminal_closed_is_not_retried_on_the_same_socket() { diff --git a/desktop/src/features/messages/lib/renderScopedReactions.test.mjs b/desktop/src/features/messages/lib/renderScopedReactions.test.mjs index 6429ecf811..37d971b268 100644 --- a/desktop/src/features/messages/lib/renderScopedReactions.test.mjs +++ b/desktop/src/features/messages/lib/renderScopedReactions.test.mjs @@ -174,3 +174,30 @@ test("failed hydration releases ids so the next render can retry", async () => { [messageId], ); }); + +for (const message of [ + "error: query timed out", + "relay returned 503 Service Unavailable: query timed out", +]) { + test(`deadline-failed hydration keeps ids claimed: ${message}`, async () => { + const messageId = hex("1"); + const queryClient = makeQueryClientStub([event(messageId, 9)]); + + await hydrateRenderScopedReactions({ + channelId: CHANNEL_ID, + messageIds: [messageId], + queryClient, + deps: { + fetchReactionEventsForMessages: async () => { + throw new Error(message); + }, + }, + }); + + // Still claimed: the next render must not re-send the same slow read. + assert.deepEqual( + claimUnhydratedRenderScopedReactionIds(CHANNEL_ID, [messageId]), + [], + ); + }); +} diff --git a/desktop/src/features/messages/lib/renderScopedReactions.ts b/desktop/src/features/messages/lib/renderScopedReactions.ts index 2c35cdf79e..e5128770e8 100644 --- a/desktop/src/features/messages/lib/renderScopedReactions.ts +++ b/desktop/src/features/messages/lib/renderScopedReactions.ts @@ -6,6 +6,7 @@ import type { TimelineMessage } from "../types"; import { relayClient } from "@/shared/api/relayClient"; import { buildChannelReactionAuxFilter } from "@/shared/api/relayChannelFilters"; import type { RelayEvent } from "@/shared/api/types"; +import { isQueryDeadlineError } from "@/shared/lib/relayError"; export type RenderScopedReactionDeps = { fetchReactionEventsForMessages: ( @@ -24,9 +25,22 @@ const defaultDeps: RenderScopedReactionDeps = { }; const hydratedMessageIdsByChannel = new Map>(); +// Ids held claimed after a relay deadline, so automatic re-renders skip them +// until the user reopens the channel. +const deadlineClaimedIdsByChannel = new Map>(); export function resetRenderScopedReactionHydration() { hydratedMessageIdsByChannel.clear(); + deadlineClaimedIdsByChannel.clear(); +} + +export function releaseDeadlineClaimedReactionIds(channelId: string) { + const ids = deadlineClaimedIdsByChannel.get(channelId); + if (!ids) { + return; + } + deadlineClaimedIdsByChannel.delete(channelId); + releaseRenderScopedReactionIds(channelId, [...ids]); } function hydratedSetForChannel(channelId: string): Set { @@ -130,7 +144,19 @@ export async function hydrateRenderScopedReactions(input: { (current = []) => sortMessages([...current, ...reactionEvents]), ); } catch (error) { - releaseRenderScopedReactionIds(input.channelId, messageIds); + // Keep deadline-failed ids claimed: releasing them lets the next render + // re-send the same slow `#e` read. Reopening the channel releases them; + // other failures stay retryable immediately. + if (isQueryDeadlineError(error)) { + let held = deadlineClaimedIdsByChannel.get(input.channelId); + if (!held) { + held = new Set(); + deadlineClaimedIdsByChannel.set(input.channelId, held); + } + for (const id of messageIds) held.add(id); + } else { + releaseRenderScopedReactionIds(input.channelId, messageIds); + } console.error( "Failed to hydrate visible reactions for channel", input.channelId, diff --git a/desktop/src/features/messages/lib/useRenderScopedReactionHydration.jsdom-test.mjs b/desktop/src/features/messages/lib/useRenderScopedReactionHydration.jsdom-test.mjs new file mode 100644 index 0000000000..97d3d6d2af --- /dev/null +++ b/desktop/src/features/messages/lib/useRenderScopedReactionHydration.jsdom-test.mjs @@ -0,0 +1,124 @@ +/** + * Reopen recovery for deadline-held reactions, through the production hook. + * + * A reaction fetch that hits the relay deadline keeps its ids claimed so + * automatic re-renders do not re-send the slow read. Reopening the channel is + * the explicit retry: the hook's `channelId` effect releases the held ids. + * + * Falsifiability: deleting the release effect in + * `useRenderScopedReactionHydration.ts` leaves the reopen with no fetch. + */ + +import assert from "node:assert/strict"; +import { afterEach, mock, test } from "node:test"; + +import React, { act } from "react"; +import { createRoot } from "react-dom/client"; +import { QueryClient, QueryClientProvider } from "@tanstack/react-query"; + +import { relayClient } from "@/shared/api/relayClient"; +import { channelMessagesKey } from "./messageQueryKeys.ts"; +import { resetRenderScopedReactionHydration } from "./renderScopedReactions.ts"; +import { useRenderScopedReactionHydration } from "./useRenderScopedReactionHydration.ts"; + +const CHANNEL_A = "36411e44-0e2d-4cfe-bd6e-567eb169db9f"; +const CHANNEL_B = "8a1c3f52-6d0e-4b7a-9c21-0f5e7d3b2a10"; +const MESSAGE_ID = "1".repeat(64); +const REACTION = { + id: "9".repeat(64), + pubkey: "a".repeat(64), + kind: 7, + created_at: 1_700_000_000, + content: "✅", + tags: [["e", MESSAGE_ID]], + sig: "sig", +}; + +afterEach(() => { + mock.restoreAll(); + resetRenderScopedReactionHydration(); +}); + +function Harness({ channelId, entries }) { + useRenderScopedReactionHydration({ + activeChannel: { id: channelId, channelType: "stream" }, + mainTimelineEntries: entries, + threadHeadMessage: null, + threadMessages: [], + }); + return null; +} + +async function flush() { + // Hydration is deferred with window.setTimeout(0). + await act(async () => { + await new Promise((resolve) => setTimeout(resolve, 10)); + }); +} + +test("reopening a channel refetches deadline-held reactions; same-channel re-renders do not", async () => { + const requests = []; + let failWithDeadline = true; + mock.method(relayClient, "fetchAuxEventsByReference", async (channelId) => { + requests.push(channelId); + if (channelId === CHANNEL_A && failWithDeadline) { + throw new Error("error: query timed out"); + } + return channelId === CHANNEL_A ? [REACTION] : []; + }); + mock.method(console, "error", () => {}); + + const queryClient = new QueryClient(); + queryClient.setQueryData(channelMessagesKey(CHANNEL_A), []); + const container = document.createElement("div"); + const root = createRoot(container); + const render = (channelId) => + act(() => { + root.render( + React.createElement( + QueryClientProvider, + { client: queryClient }, + React.createElement(Harness, { + channelId, + // Fresh array each render, as a live timeline update produces. + entries: [{ message: { id: MESSAGE_ID }, summary: null }], + }), + ), + ); + }); + + await render(CHANNEL_A); + await flush(); + assert.deepEqual( + requests, + [CHANNEL_A], + "first open fetches and hits the deadline", + ); + + failWithDeadline = false; + await render(CHANNEL_A); + await flush(); + assert.deepEqual( + requests, + [CHANNEL_A], + "same-channel re-render keeps ids held", + ); + + await render(CHANNEL_B); + await flush(); + await render(CHANNEL_A); + await flush(); + assert.deepEqual( + requests, + [CHANNEL_A, CHANNEL_B, CHANNEL_A], + "reopening channel A refetches its held ids", + ); + assert.ok( + queryClient + .getQueryData(channelMessagesKey(CHANNEL_A)) + .some((event) => event.id === REACTION.id), + "recovered reaction lands in the channel cache", + ); + + act(() => root.unmount()); +}); diff --git a/desktop/src/features/messages/lib/useRenderScopedReactionHydration.ts b/desktop/src/features/messages/lib/useRenderScopedReactionHydration.ts index 8bc3f7724c..641bf80cde 100644 --- a/desktop/src/features/messages/lib/useRenderScopedReactionHydration.ts +++ b/desktop/src/features/messages/lib/useRenderScopedReactionHydration.ts @@ -7,6 +7,7 @@ import type { Channel } from "@/shared/api/types"; import { collectRenderScopedReactionMessageIds, hydrateRenderScopedReactions, + releaseDeadlineClaimedReactionIds, } from "./renderScopedReactions"; export function useRenderScopedReactionHydration(input: { @@ -16,6 +17,13 @@ export function useRenderScopedReactionHydration(input: { threadMessages: MainTimelineEntry[]; }) { const queryClient = useQueryClient(); + const channelId = input.activeChannel?.id; + + // Opening a channel is the explicit retry for reactions a relay deadline + // held back. Declared first so it runs before this render's hydration. + React.useEffect(() => { + if (channelId) releaseDeadlineClaimedReactionIds(channelId); + }, [channelId]); React.useEffect(() => { const channelId = input.activeChannel?.id; diff --git a/desktop/src/features/messages/queryDeadlineRetry.test.mjs b/desktop/src/features/messages/queryDeadlineRetry.test.mjs new file mode 100644 index 0000000000..c8dd559bfa --- /dev/null +++ b/desktop/src/features/messages/queryDeadlineRetry.test.mjs @@ -0,0 +1,154 @@ +/** + * Deadline-retry contract, exercised under the production QueryClient: + * a read that hit the relay's `query timed out` deadline is fetched once; an + * ordinary failure, including a client-side request timeout, keeps its retries. + * Removing the predicate from `createBuzzQueryClient` or `useThreadReplies` + * makes the deadline cases here fetch more than once. + */ + +import assert from "node:assert/strict"; +import { mock } from "node:test"; +import test from "node:test"; +import { registerHooks } from "node:module"; + +import { JSDOM } from "jsdom"; + +globalThis.__tauriGetThreadReplies = async () => ({ + events: [], + nextCursor: null, +}); + +registerHooks({ + resolve(specifier, context, nextResolve) { + if (specifier === "@/shared/api/tauri") { + return { shortCircuit: true, url: "buzz-deadline-stub:tauri" }; + } + return nextResolve(specifier, context); + }, + load(url, context, nextLoad) { + if (url === "buzz-deadline-stub:tauri") { + return { + format: "module", + shortCircuit: true, + source: `export async function getThreadReplies(...args) { + return globalThis.__tauriGetThreadReplies(...args); +} +export default {};`, + }; + } + return nextLoad(url, context); + }, +}); + +const dom = new JSDOM("", { + url: "http://localhost", + pretendToBeVisual: true, +}); +dom.window.document.hasFocus = () => true; +Object.assign(globalThis, { + IS_REACT_ACT_ENVIRONMENT: true, + document: dom.window.document, + HTMLElement: dom.window.HTMLElement, + window: dom.window, +}); + +const { act, cleanup, renderHook } = await import("@testing-library/react"); +const { createElement } = await import("react"); +const { QueryClientProvider, useQuery } = await import("@tanstack/react-query"); +const { createBuzzQueryClient } = await import("@/shared/api/queryClient"); +const { useThreadReplies, useThreadRepliesForRoots } = await import( + "./useThreadReplies.ts" +); + +const CASES = [ + { + name: "client request timeout", + message: "relay unreachable: request timed out", + deadline: false, + }, + { + name: "relay deadline", + message: "relay returned 503 Service Unavailable: query timed out", + deadline: true, + }, + { + name: "ordinary error", + message: "relay returned 500: internal server error", + deadline: false, + }, +]; + +// Mount `useHook` under the production client, drive every retry delay with +// fake timers until the query settles in error, and return the fetch count. +async function fetchCountUntilError(useHook, isSettled) { + mock.timers.enable({ apis: ["setTimeout"] }); + const queryClient = createBuzzQueryClient(); + const wrapper = ({ children }) => + createElement(QueryClientProvider, { client: queryClient }, children); + try { + const { result, unmount } = renderHook(useHook, { wrapper }); + for (let i = 0; i < 20 && !isSettled(result.current); i++) { + mock.timers.tick(60_000); + await act(async () => { + await new Promise((resolve) => setImmediate(resolve)); + }); + } + assert.ok(isSettled(result.current), "query never settled in error"); + unmount(); + } finally { + cleanup(); + queryClient.clear(); + mock.timers.reset(); + } +} + +for (const { name, message, deadline } of CASES) { + test(`createBuzzQueryClient default retry: ${name}`, async () => { + let calls = 0; + await fetchCountUntilError( + () => + useQuery({ + queryKey: ["deadline-default", name], + queryFn: async () => { + calls += 1; + throw new Error(message); + }, + }), + (r) => r.isError, + ); + assert.equal(calls, deadline ? 1 : 2); + }); + + test(`useThreadRepliesForRoots (3 roots) retry: ${name}`, async () => { + const calls = new Map(); + globalThis.__tauriGetThreadReplies = async (rootId) => { + calls.set(rootId, (calls.get(rootId) ?? 0) + 1); + throw new Error(message); + }; + const channel = { id: `chan-roots-${name}`, channelType: "group" }; + const roots = ["root-a", "root-b", "root-c"]; + await fetchCountUntilError( + () => useThreadRepliesForRoots(channel, roots), + (r) => r.isError && !r.isPending, + ); + assert.deepEqual( + Object.fromEntries(calls), + Object.fromEntries(roots.map((root) => [root, deadline ? 1 : 2])), + ); + }); + + test(`useThreadReplies single-root retry: ${name}`, async () => { + let calls = 0; + globalThis.__tauriGetThreadReplies = async () => { + calls += 1; + throw new Error(message); + }; + const channel = { id: `chan-single-${name}`, channelType: "group" }; + await fetchCountUntilError( + () => useThreadReplies(channel, "root-single"), + (r) => r.isError, + ); + // useThreadReplies keeps its own `< 3` retries for ordinary failures. + assert.equal(calls, deadline ? 1 : 4); + }); +} diff --git a/desktop/src/features/messages/useThreadReplies.ts b/desktop/src/features/messages/useThreadReplies.ts index 9ad86e46a8..e23eb2a189 100644 --- a/desktop/src/features/messages/useThreadReplies.ts +++ b/desktop/src/features/messages/useThreadReplies.ts @@ -11,6 +11,7 @@ import { sortMessages, } from "@/features/messages/lib/messageQueryKeys"; import { getThreadReplies } from "@/shared/api/tauri"; +import { isQueryDeadlineError } from "@/shared/lib/relayError"; import type { Channel, RelayEvent, @@ -163,7 +164,10 @@ export function useThreadReplies( // throws on attempts 1 and 2; attempt 3 records exhaustion first so // loadThreadReplies returns data directly — the terminal attempt always // resolves to success. - retry: 3, + // A read that hit the relay's statement deadline is not retried: + // each retry would re-run the same slow server-side query. + retry: (failureCount, error) => + failureCount < 3 && !isQueryDeadlineError(error), retryDelay: (attempt) => Math.min(1_000 * 2 ** attempt, 30_000), }); diff --git a/desktop/src/features/profile/profileBatchResilience.test.mjs b/desktop/src/features/profile/profileBatchResilience.test.mjs index 53f8c1ff11..7939581600 100644 --- a/desktop/src/features/profile/profileBatchResilience.test.mjs +++ b/desktop/src/features/profile/profileBatchResilience.test.mjs @@ -43,8 +43,13 @@ test("useUsersBatchQuery: global queryClient defaults are unchanged", async () = new URL("../../shared/api/queryClient.ts", import.meta.url), "utf8", ); - // Global retry must remain 1 — other queries chose that semantics. - assert.match(source, /retry:\s*1/, "global retry default must remain 1"); + // Global retry budget must remain 1 — other queries chose that semantics. + // Query-deadline failures are exempt so a slow server query is not re-run. + assert.match( + source, + /failureCount < 1 && !isQueryDeadlineError\(error\)/, + "global retry default must remain 1, skipping query deadlines", + ); // Global refetchOnWindowFocus must remain false. assert.match( source, diff --git a/desktop/src/shared/api/queryClient.ts b/desktop/src/shared/api/queryClient.ts index 6302f4e064..5590f1d967 100644 --- a/desktop/src/shared/api/queryClient.ts +++ b/desktop/src/shared/api/queryClient.ts @@ -1,5 +1,6 @@ import { focusManager, QueryClient } from "@tanstack/react-query"; +import { isQueryDeadlineError } from "@/shared/lib/relayError"; import { isAppFocused, subscribeAppFocus, @@ -25,7 +26,10 @@ export function createBuzzQueryClient() { return new QueryClient({ defaultOptions: { queries: { - retry: 1, + // One retry, except after the relay's `query timed out` answer: that + // would re-run the same slow server-side query. + retry: (failureCount, error) => + failureCount < 1 && !isQueryDeadlineError(error), refetchOnWindowFocus: false, networkMode: "always", gcTime: 5 * 60 * 1_000, diff --git a/desktop/src/shared/api/relayClosedPolicy.test.mjs b/desktop/src/shared/api/relayClosedPolicy.test.mjs index 2e5cad4b7c..49f8189cca 100644 --- a/desktop/src/shared/api/relayClosedPolicy.test.mjs +++ b/desktop/src/shared/api/relayClosedPolicy.test.mjs @@ -26,6 +26,7 @@ test("classifyRelayClosed: terminal messages return terminal", () => { "unsupported: filter", "error: mixed search and non-search filters not supported", "error: too many subscriptions", + "error: query timed out", ]) { assert.equal(classifyRelayClosed(message), "terminal", message); } diff --git a/desktop/src/shared/api/relayClosedPolicy.ts b/desktop/src/shared/api/relayClosedPolicy.ts index 9e747a2df1..a5ff5372ef 100644 --- a/desktop/src/shared/api/relayClosedPolicy.ts +++ b/desktop/src/shared/api/relayClosedPolicy.ts @@ -32,7 +32,10 @@ export function classifyRelayClosed(message: string): RelayClosedClass { normalized.startsWith("duplicate:") || normalized.startsWith("unsupported:") || normalized.startsWith("error: mixed search") || - normalized.startsWith("error: too many subscriptions") + normalized.startsWith("error: too many subscriptions") || + // Server statement deadline: re-sending the same REQ re-runs the same + // slow query, so a live retry loop would hammer the database. + normalized.startsWith("error: query timed out") ) { return "terminal"; } diff --git a/desktop/src/shared/api/relayClosedRecovery.test.mjs b/desktop/src/shared/api/relayClosedRecovery.test.mjs index de75aad3ba..c09b90e4c5 100644 --- a/desktop/src/shared/api/relayClosedRecovery.test.mjs +++ b/desktop/src/shared/api/relayClosedRecovery.test.mjs @@ -670,6 +670,35 @@ test("terminal CLOSED deletes subscription and does not retry", () => { assert.equal(firedAt.length, 0, "terminal CLOSED must not retry"); }); +test("live CLOSED query deadline retries with backoff instead of removing", () => { + resetAll(0); + const firedAt = []; + const subscriptions = new Map([ + [ + "live-1", + { + mode: "live", + filter: { kinds: [9], "#h": ["ch-1"], limit: 1000 }, + onEvent: () => {}, + resolveReady: () => {}, + }, + ], + ]); + handleRelayClosed({ + subscriptions, + subId: "live-1", + message: "error: query timed out", + sendReq: () => { + firedAt.push(fakeNow); + return Promise.resolve(); + }, + }); + assert.equal(subscriptions.has("live-1"), true, "live sub must survive"); + assert.equal(firedAt.length, 0, "retry waits for backoff"); + tickTo(10_000); + assert.equal(firedAt.length, 1, "live sub must be re-sent after backoff"); +}); + // ── Test: rejecting closeSubscription does not produce an unhandled rejection ─ // // Load-bearing for the `.catch(() => {})` guard on the op-timeout CLOSE send. diff --git a/desktop/src/shared/api/relayClosedRecovery.ts b/desktop/src/shared/api/relayClosedRecovery.ts index cf04d83126..348d55e299 100644 --- a/desktop/src/shared/api/relayClosedRecovery.ts +++ b/desktop/src/shared/api/relayClosedRecovery.ts @@ -1,4 +1,5 @@ import { classifyRelayClosed } from "@/shared/api/relayClosedPolicy"; +import { isQueryDeadlineError } from "@/shared/lib/relayError"; import { activateRateLimit, parseRateLimitHint, @@ -132,7 +133,13 @@ function recoverLiveSubscriptionFromClosed({ subscription.resolveReady?.("closed"); subscription.resolveReady = undefined; - const closedClass = classifyRelayClosed(message); + // A deadline on a live sub is treated as retryable: resubscribe with the + // same filter under the 1-30s backoff, which can keep retrying at the cap. + // `since` is deliberately not advanced to now; that could skip events + // missed while the sub was closed. + const closedClass = isQueryDeadlineError(message) + ? "retryable" + : classifyRelayClosed(message); if (closedClass === "terminal") { // Auth/access/filter failure — permanently remove the subscription so it diff --git a/desktop/src/shared/lib/relayError.test.mjs b/desktop/src/shared/lib/relayError.test.mjs index 7ae121f2b5..07b018b9b1 100644 --- a/desktop/src/shared/lib/relayError.test.mjs +++ b/desktop/src/shared/lib/relayError.test.mjs @@ -1,7 +1,7 @@ import assert from "node:assert/strict"; import test from "node:test"; -import { isRelayUnreachableError } from "./relayError.ts"; +import { isQueryDeadlineError, isRelayUnreachableError } from "./relayError.ts"; test("isRelayUnreachableError: Error with prefix returns true", () => { assert.equal( @@ -55,3 +55,39 @@ test("isRelayUnreachableError: plain object returns false", () => { false, ); }); + +test("isQueryDeadlineError: relay statement deadline, HTTP and WS forms", () => { + assert.equal( + isQueryDeadlineError( + new Error("relay returned 503 Service Unavailable: query timed out"), + ), + true, + ); + assert.equal(isQueryDeadlineError("error: query timed out"), true); +}); + +test("isQueryDeadlineError: client-side timeouts stay retryable", () => { + for (const message of [ + "relay unreachable: request timed out", + "relay request timed out", + "relay request timed out or cancelled", + ]) { + assert.equal(isQueryDeadlineError(new Error(message)), false, message); + } +}); + +test("isQueryDeadlineError: other relay errors stay retryable", () => { + assert.equal( + isQueryDeadlineError( + new Error( + "relay returned 500 Internal Server Error: internal server error", + ), + ), + false, + ); + assert.equal( + isQueryDeadlineError(new Error("relay unreachable: 403")), + false, + ); + assert.equal(isQueryDeadlineError(undefined), false); +}); diff --git a/desktop/src/shared/lib/relayError.ts b/desktop/src/shared/lib/relayError.ts index ca16aa41e2..285a8651fd 100644 --- a/desktop/src/shared/lib/relayError.ts +++ b/desktop/src/shared/lib/relayError.ts @@ -32,3 +32,14 @@ export function isRelayUnreachableError(error: unknown): boolean { } return false; } + +/** + * Returns true only for the relay's own statement-deadline answer: HTTP 503 + * `query timed out` or WS CLOSED `error: query timed out`. Retrying re-runs + * the same expensive query, so callers should not. Client-side timeouts + * (`request timed out`) are network stalls and stay retryable. + */ +export function isQueryDeadlineError(error: unknown): boolean { + const message = error instanceof Error ? error.message : String(error); + return message.includes("query timed out"); +} diff --git a/mobile/lib/features/channels/channel_detail_page.dart b/mobile/lib/features/channels/channel_detail_page.dart index 468dbb0486..d518bd1878 100644 --- a/mobile/lib/features/channels/channel_detail_page.dart +++ b/mobile/lib/features/channels/channel_detail_page.dart @@ -25,6 +25,7 @@ import '../../shared/widgets/frosted_app_bar.dart'; import '../../shared/widgets/frosted_scaffold.dart'; import '../../shared/widgets/flapping_bee.dart'; import '../../shared/widgets/keyboard_dismiss_on_drag.dart'; +import '../../shared/widgets/load_error_view.dart'; import '../../shared/widgets/ios_glass_navigation_button.dart'; import '../../shared/widgets/masked_avatar_badge.dart'; import '../../shared/widgets/message_author_meta.dart'; @@ -715,12 +716,10 @@ class ChannelDetailPage extends HookConsumerWidget { titleContentHeight: appBarTitleContentHeight, ), ), - child: Center( - child: Text( - 'Failed to load messages', - style: context.textTheme.bodyMedium?.copyWith( - color: context.colors.error, - ), + child: LoadErrorView( + message: 'Failed to load messages', + onRetry: () => ref.invalidate( + channelMessagesProvider(channel.id), ), ), ), diff --git a/mobile/lib/features/channels/channel_messages_provider.dart b/mobile/lib/features/channels/channel_messages_provider.dart index 221aef367a..a87fdf7c7f 100644 --- a/mobile/lib/features/channels/channel_messages_provider.dart +++ b/mobile/lib/features/channels/channel_messages_provider.dart @@ -247,6 +247,8 @@ class ChannelMessagesNotifier extends Notifier>> { } catch (error) { _initialWindowQueryInFlight = false; _liveSummaryRootsDuringInitialWindowQuery.clear(); + // Legacy history would re-run the timed-out work another way. + if (isRelayDeadlineError(error)) rethrow; debugPrint( '[ChannelMessagesNotifier] channel window unavailable for $channelId, falling back to WS history: $error', ); diff --git a/mobile/lib/features/channels/channel_messages_provider/thread_summaries.dart b/mobile/lib/features/channels/channel_messages_provider/thread_summaries.dart index 7fa36c2b14..7d22de342b 100644 --- a/mobile/lib/features/channels/channel_messages_provider/thread_summaries.dart +++ b/mobile/lib/features/channels/channel_messages_provider/thread_summaries.dart @@ -332,7 +332,8 @@ extension _ThreadSummaryState on ChannelMessagesNotifier { } } catch (error) { if (!current()) return; - if (attempt < 2) { + // Re-sending a timed-out recount re-runs the same slow scan. + if (attempt < 2 && !isRelayDeadlineError(error)) { // Retain this active queue slot during backoff, so retries share the // same concurrency budget and stop when newer work supersedes them. await Future.delayed(Duration(milliseconds: 500 << attempt)); diff --git a/mobile/lib/features/channels/channels_provider.dart b/mobile/lib/features/channels/channels_provider.dart index c5a77ba930..982e39fa2a 100644 --- a/mobile/lib/features/channels/channels_provider.dart +++ b/mobile/lib/features/channels/channels_provider.dart @@ -338,8 +338,18 @@ class ChannelsNotifier extends AsyncNotifier> { _fetchLastMessageEvents(session, activeChannels), ); final lastMessageMap = {}; + // An unavailable batch keeps the timestamps already known rather than + // installing channels whose latest message looks absent. + if (events == null) { + for (final channel in state.value ?? const []) { + final at = channel.lastMessageAt; + if (at != null) { + lastMessageMap[channel.id] = at.millisecondsSinceEpoch ~/ 1000; + } + } + } final mutedChannelIds = _mutedChannelIds(); - for (final event in events) { + for (final event in events ?? const []) { final channelId = event.channelId; if (channelId == null) continue; final channel = channelById[channelId]; @@ -423,7 +433,7 @@ class ChannelsNotifier extends AsyncNotifier> { /// bridge request. The relay preserves NIP-01 per-filter limits while /// executing the filters with bounded concurrency, avoiding an unbounded /// burst of websocket REQs on communities with many channels. - Future> _fetchLastMessageEvents( + Future?> _fetchLastMessageEvents( RelaySessionNotifier session, List channels, ) async { @@ -447,7 +457,8 @@ class ChannelsNotifier extends AsyncNotifier> { ); } - Future> _fetchChannelHistoryBatch( + /// Returns null when the batch is unavailable: it hit a relay deadline. + Future?> _fetchChannelHistoryBatch( RelaySessionNotifier session, List filters, { required String operation, @@ -457,6 +468,11 @@ class ChannelsNotifier extends AsyncNotifier> { try { return await session.queryRelay(filters); } catch (error) { + // Per-filter fallback would re-run the timed-out work another way. + if (isRelayDeadlineError(error)) { + debugPrint('[ChannelsNotifier] batched $operation hit the deadline'); + return null; + } debugPrint( '[ChannelsNotifier] batched $operation failed; ' 'using bounded websocket fallback: $error', @@ -465,13 +481,19 @@ class ChannelsNotifier extends AsyncNotifier> { const fallbackConcurrency = 4; final events = []; + var deadline = false; for (var start = 0; start < filters.length; start += fallbackConcurrency) { + // Stop sending once a filter hit the deadline; partial events are not + // a result. + if (deadline) return null; final end = min(start + fallbackConcurrency, filters.length); final results = await Future.wait( filters.sublist(start, end).map((filter) async { try { return await session.fetchHistory(filter); - } catch (_) { + } catch (error) { + // A timed-out filter makes the batch unavailable, not empty. + if (isRelayDeadlineError(error)) deadline = true; return const []; } }), @@ -480,6 +502,7 @@ class ChannelsNotifier extends AsyncNotifier> { events.addAll(result); } } + if (deadline) return null; return events; } @@ -592,6 +615,8 @@ class ChannelsNotifier extends AsyncNotifier> { filters, operation: 'unread catch-up', ); + // Unavailable: keep the unread state already observed. + if (events == null) return; // The relay round-trip above is the window Jed's probes park in: a newer // refresh, a community switch or an identity switch here means every // write below belongs to a channel list the user has left. @@ -605,7 +630,7 @@ class ChannelsNotifier extends AsyncNotifier> { } } - var recorded = false; + final recordedAtByChannel = {}; for (final event in events) { final channelId = event.channelId; if (channelId == null) continue; @@ -626,15 +651,25 @@ class ChannelsNotifier extends AsyncNotifier> { continue; } _recordUnreadEvent(channel, event, myPk); - recorded = true; + recordedAtByChannel[channelId] = max( + recordedAtByChannel[channelId] ?? 0, + event.createdAt, + ); } // Republish only when this catch-up actually changed unread state. A // batch that recorded nothing has nothing to show, and a failed or // superseded batch must not repaint another refresh's list: the retired // check above already returned in that case, and no await separates it // from here, so a second check would be dead code. - if (recorded) { - state = state.whenData((channels) => List.of(channels)); + // Recorded events also advance `lastMessageAt`, as live events do: a + // deadline-unavailable latest-message batch leaves it unset. + if (recordedAtByChannel.isNotEmpty) { + state = state.whenData( + (channels) => [ + for (final channel in channels) + _advanceLastMessageAt(channel, recordedAtByChannel[channel.id]), + ], + ); } } catch (error) { if (!ref.mounted) return; @@ -642,6 +677,17 @@ class ChannelsNotifier extends AsyncNotifier> { } } + static Channel _advanceLastMessageAt(Channel channel, int? createdAt) { + if (createdAt == null) return channel; + final at = DateTime.fromMillisecondsSinceEpoch( + createdAt * 1000, + isUtc: true, + ); + final current = channel.lastMessageAt; + if (current != null && !at.isAfter(current)) return channel; + return channel.copyWith(lastMessageAt: at); + } + void _handleLiveEvent(NostrEvent event) { final channelId = event.channelId; if (channelId == null) return; diff --git a/mobile/lib/features/channels/thread_detail_helpers.dart b/mobile/lib/features/channels/thread_detail_helpers.dart index 7ff39fac53..fdb92f6020 100644 --- a/mobile/lib/features/channels/thread_detail_helpers.dart +++ b/mobile/lib/features/channels/thread_detail_helpers.dart @@ -173,3 +173,23 @@ class _ThreadTypingIndicator extends StatelessWidget { ); } } + +/// Display evidence while the authoritative thread query has no value (still +/// loading, or failed on first load): the route snapshot plus live, cached +/// and optimistic replies. The page keeps the query's loading/error status, +/// so this list is never presented as complete, and nothing is re-queried. +List _provisionalThreadMessages( + List routeSnapshot, + List observed, + List liveChannelEvents, +) { + final byId = { + for (final message in routeSnapshot) + if (!_isDeletedBy(liveChannelEvents, message.id)) message.id: message, + for (final message in observed) message.id: message, + }; + return byId.values.toList()..sort((a, b) { + final order = a.createdAt.compareTo(b.createdAt); + return order != 0 ? order : a.id.compareTo(b.id); + }); +} diff --git a/mobile/lib/features/channels/thread_detail_page.dart b/mobile/lib/features/channels/thread_detail_page.dart index 0bb4cedb34..56d7015b0f 100644 --- a/mobile/lib/features/channels/thread_detail_page.dart +++ b/mobile/lib/features/channels/thread_detail_page.dart @@ -4,6 +4,7 @@ import 'dart:math' as math; import 'package:flutter/material.dart'; import 'package:flutter_hooks/flutter_hooks.dart'; import 'package:hooks_riverpod/hooks_riverpod.dart'; +import 'package:lucide_icons_flutter/lucide_icons.dart'; import 'package:scrollable_positioned_list/scrollable_positioned_list.dart'; import '../../shared/mentions/agent_identity_provider.dart'; @@ -148,8 +149,13 @@ class ThreadDetailPage extends HookConsumerWidget { liveChannelEvents, threadHead.id, ); - final allMsgs = fetchedReplies == null - ? allMessages + final allMsgs = fetchedReplies == null || !relayRepliesAvailable + ? _provisionalThreadMessages( + allMessages, + fetchedReplies ?? + formatTimeline(liveChannelEvents, currentPubkey: currentPubkey), + liveChannelEvents, + ) : [ // Only fall back to the pushed-route snapshot when neither source // carries the head, and no live deletion has suppressed it. That @@ -894,6 +900,8 @@ class ThreadDetailPage extends HookConsumerWidget { bottomInset: timelineBottomInset, replies: replies, relayReplyState: relayReplyState, + onRetryReplies: () => + ref.invalidate(threadRepliesProvider(repliesArgs)), localSendAnimations: localSendAnimations, trackActiveScrollPosition: trackActiveScrollPosition, headIsDeleted: liveDeletionHidesHead, diff --git a/mobile/lib/features/channels/thread_detail_page/message_list.dart b/mobile/lib/features/channels/thread_detail_page/message_list.dart index a33aa9a4ee..28160ee88b 100644 --- a/mobile/lib/features/channels/thread_detail_page/message_list.dart +++ b/mobile/lib/features/channels/thread_detail_page/message_list.dart @@ -10,6 +10,7 @@ class _ThreadMessageList extends StatelessWidget { final double bottomInset; final List replies; final AsyncValue> relayReplyState; + final VoidCallback onRetryReplies; final Map localSendAnimations; final Widget Function(Widget child) trackActiveScrollPosition; final bool headIsDeleted; @@ -36,6 +37,7 @@ class _ThreadMessageList extends StatelessWidget { required this.bottomInset, required this.replies, required this.relayReplyState, + required this.onRetryReplies, required this.localSendAnimations, required this.trackActiveScrollPosition, required this.headIsDeleted, @@ -164,6 +166,17 @@ class _ThreadMessageList extends StatelessWidget { ), ), ), + if (relayReplyState.hasError && + !relayReplyState.isLoading) + IconButton( + key: const ValueKey('thread-replies-retry'), + onPressed: onRetryReplies, + tooltip: 'Retry', + icon: const Icon( + LucideIcons.refreshCcw, + size: 16, + ), + ), const SizedBox(width: Grid.xxs), Expanded( child: Divider( diff --git a/mobile/lib/features/forum/forum_posts_view.dart b/mobile/lib/features/forum/forum_posts_view.dart index 13880427cf..352c1bc73f 100644 --- a/mobile/lib/features/forum/forum_posts_view.dart +++ b/mobile/lib/features/forum/forum_posts_view.dart @@ -5,9 +5,11 @@ import 'package:flutter_hooks/flutter_hooks.dart'; import 'package:hooks_riverpod/hooks_riverpod.dart'; import 'package:lucide_icons_flutter/lucide_icons.dart'; +import '../../shared/relay/relay_closed_policy.dart'; import '../../shared/theme/theme.dart'; import '../../shared/widgets/buzz_loading_indicator.dart'; import '../../shared/widgets/frosted_app_bar.dart'; +import '../../shared/widgets/load_error_view.dart'; import '../../shared/widgets/bee_refresh_indicator.dart'; import '../channels/channel.dart'; import '../channels/compose_bar.dart'; @@ -39,10 +41,22 @@ class ForumPostsView extends HookConsumerWidget { final providerContainer = ProviderScope.containerOf(context, listen: false); final forumDelivery = ForumEventDelivery.capture(providerContainer); - // Periodic refresh (every 15s, matching desktop). + // Periodic refresh (every 15s, matching desktop). A settled deadline + // pauses polling; reopening the forum is the explicit retry. useEffect(() { + final provider = forumPostsProvider(channel.id); + // Only a deadline already settled when this surface mounts is a + // reopen; a first load that fails after mounting is not retried. + // Hooks run effects during build, so defer the invalidation past it. + if (isSettledRelayDeadline(ref.read(provider))) { + Future.microtask(() { + if (context.mounted) ref.invalidate(provider); + }); + } final timer = Stream.periodic(const Duration(seconds: 15)).listen((_) { - ref.invalidate(forumPostsProvider(channel.id)); + if (!isSettledRelayDeadline(ref.read(provider))) { + ref.invalidate(provider); + } }); return timer.cancel; }, [channel.id]); @@ -65,6 +79,8 @@ class ForumPostsView extends HookConsumerWidget { ) : null, body: postsAsync.when( + // A retry from an error shows loading, not the stale error and its Retry. + skipLoadingOnRefresh: !postsAsync.hasError, loading: () => Padding( padding: EdgeInsets.only(top: frostedAppBarHeight(context)), child: const Center( @@ -76,13 +92,9 @@ class ForumPostsView extends HookConsumerWidget { ), error: (e, _) => Padding( padding: EdgeInsets.only(top: frostedAppBarHeight(context)), - child: Center( - child: Text( - 'Failed to load posts', - style: context.textTheme.bodyMedium?.copyWith( - color: context.colors.error, - ), - ), + child: LoadErrorView( + message: 'Failed to load posts', + onRetry: () => ref.invalidate(forumPostsProvider(channel.id)), ), ), data: (response) { diff --git a/mobile/lib/features/forum/forum_thread_page.dart b/mobile/lib/features/forum/forum_thread_page.dart index 298630b42c..8b802bac4a 100644 --- a/mobile/lib/features/forum/forum_thread_page.dart +++ b/mobile/lib/features/forum/forum_thread_page.dart @@ -7,11 +7,13 @@ import 'package:hooks_riverpod/hooks_riverpod.dart'; import 'package:lucide_icons_flutter/lucide_icons.dart'; import '../../shared/mentions/agent_identity_provider.dart'; +import '../../shared/relay/relay_closed_policy.dart'; import '../../shared/theme/theme.dart'; import '../../shared/widgets/avatar_image.dart'; import '../../shared/widgets/buzz_loading_indicator.dart'; import '../../shared/widgets/frosted_app_bar.dart'; import '../../shared/widgets/frosted_scaffold.dart'; +import '../../shared/widgets/load_error_view.dart'; import '../../shared/widgets/modal_presentation.dart'; import '../channels/compose_bar.dart'; import '../channels/message_content.dart'; @@ -45,12 +47,25 @@ class ForumThreadPage extends HookConsumerWidget { forumThreadProvider((channelId: channelId, eventId: postEventId)), ); - // Periodic refresh (every 10s, matching desktop). + // Periodic refresh (every 10s, matching desktop). A settled deadline + // pauses polling; reopening the thread is the explicit retry. useEffect(() { + final provider = forumThreadProvider(( + channelId: channelId, + eventId: postEventId, + )); + // Only a deadline already settled when this surface mounts is a + // reopen; a first load that fails after mounting is not retried. + // Hooks run effects during build, so defer the invalidation past it. + if (isSettledRelayDeadline(ref.read(provider))) { + Future.microtask(() { + if (context.mounted) ref.invalidate(provider); + }); + } final timer = Stream.periodic(const Duration(seconds: 10)).listen((_) { - ref.invalidate( - forumThreadProvider((channelId: channelId, eventId: postEventId)), - ); + if (!isSettledRelayDeadline(ref.read(provider))) { + ref.invalidate(provider); + } }); return timer.cancel; }, [channelId, postEventId]); @@ -79,6 +94,8 @@ class ForumThreadPage extends HookConsumerWidget { ], ), body: threadAsync.when( + // A retry from an error shows loading, not the stale error and its Retry. + skipLoadingOnRefresh: !threadAsync.hasError, loading: () => Padding( padding: EdgeInsets.only(top: frostedAppBarHeight(context)), child: const Center( @@ -90,12 +107,10 @@ class ForumThreadPage extends HookConsumerWidget { ), error: (e, _) => Padding( padding: EdgeInsets.only(top: frostedAppBarHeight(context)), - child: Center( - child: Text( - 'Failed to load thread', - style: context.textTheme.bodyMedium?.copyWith( - color: context.colors.error, - ), + child: LoadErrorView( + message: 'Failed to load thread', + onRetry: () => ref.invalidate( + forumThreadProvider((channelId: channelId, eventId: postEventId)), ), ), ), diff --git a/mobile/lib/main.dart b/mobile/lib/main.dart index 5b40be40d3..6c1aa734df 100644 --- a/mobile/lib/main.dart +++ b/mobile/lib/main.dart @@ -6,6 +6,7 @@ import 'app.dart'; import 'features/age_gate/age_signal_push_bootstrap.dart'; import 'features/invites/invite_join_provider.dart'; import 'shared/push/push_bridge.dart'; +import 'shared/relay/relay_closed_policy.dart'; import 'shared/theme/theme_provider.dart'; void main() => runBuzzApp(const App()); @@ -18,16 +19,26 @@ Future runBuzzApp(Widget app) async { // Pre-load preferences so the first frame uses the saved theme/accent. final prefs = await SharedPreferences.getInstance(); - runApp( - ProviderScope( - overrides: [ - savedPrefsProvider.overrideWithValue(prefs), - inviteJoinRecoveryProvider.overrideWith( - (ref) => - (scope) => buildMobileInviteJoinRecovery(ref, scope), - ), - ], - child: AgeSignalPushBootstrap(child: app), - ), - ); + runApp(buildRootProviderScope(prefs: prefs, child: app)); } + +/// The app's root scope, shared with tests so its production wiring is +/// asserted rather than re-declared. +ProviderScope buildRootProviderScope({ + required SharedPreferences prefs, + required Widget child, +}) => ProviderScope( + // A relay statement deadline cannot resolve on retry — the same expensive + // query would re-run and hit the same limit. Return null (no retry) for + // deadline errors and fall through to the default exponential backoff for + // everything else. + retry: relayProviderRetry, + overrides: [ + savedPrefsProvider.overrideWithValue(prefs), + inviteJoinRecoveryProvider.overrideWith( + (ref) => + (scope) => buildMobileInviteJoinRecovery(ref, scope), + ), + ], + child: AgeSignalPushBootstrap(child: child), +); diff --git a/mobile/lib/shared/relay/relay_closed_policy.dart b/mobile/lib/shared/relay/relay_closed_policy.dart index d39084b189..4013470c7c 100644 --- a/mobile/lib/shared/relay/relay_closed_policy.dart +++ b/mobile/lib/shared/relay/relay_closed_policy.dart @@ -1,3 +1,50 @@ +import 'dart:convert'; + +import 'package:hooks_riverpod/hooks_riverpod.dart'; + +import 'relay_client.dart'; + +// Shared constant so [isRelayDeadlineError] and [classifyRelayClosed] cannot +// drift apart. +const _queryTimedOutPrefix = 'error: query timed out'; + +/// Returns true when [error] is a relay server-side statement deadline that +/// cannot be resolved by retrying the same query. +/// +/// Two surfaces carry the same deadline signal: +/// - HTTP `/query` or `/count`: [RelayException] with status 503 and a JSON +/// body containing `"error": "query timed out"`. +/// - WebSocket CLOSED: a plain [Exception] whose message is +/// `"error: query timed out"` (the relay's stable CLOSED reason string). +/// +/// Both surfaces are checked so the caller (e.g. a Riverpod retry hook) does +/// not need to distinguish which transport produced the error. +bool isRelayDeadlineError(Object error) { + if (error is RelayException && error.statusCode == 503) { + try { + final decoded = jsonDecode(error.body); + if (decoded is Map) { + final message = decoded['error']; + if (message is String && + message.trim().toLowerCase() == 'query timed out') { + return true; + } + } + } on FormatException { + // Non-JSON 503 — not a deadline. + } + return false; + } + // WebSocket history CLOSED: Exception("error: query timed out") + // Strip the "Exception: " prefix Flutter adds to Exception.toString(), then + // check via classifyRelayClosed so this path shares the same source of truth. + var message = error.toString().trim().toLowerCase(); + const prefix = 'exception: '; + if (message.startsWith(prefix)) message = message.substring(prefix.length); + return classifyRelayClosed(message) == RelayClosedClass.terminal && + message.startsWith(_queryTimedOutPrefix); +} + /// Recovery policy for a relay `CLOSED` subscription message. enum RelayClosedClass { /// A transient failure that may recover when the same REQ is retried. @@ -24,7 +71,10 @@ RelayClosedClass classifyRelayClosed(String message) { normalized.startsWith('duplicate:') || normalized.startsWith('unsupported:') || normalized.startsWith('error: mixed search') || - normalized.startsWith('error: too many subscriptions')) { + normalized.startsWith('error: too many subscriptions') || + // Server statement deadline: re-sending the same REQ re-runs the same + // slow query. + normalized.startsWith(_queryTimedOutPrefix)) { return RelayClosedClass.terminal; } return RelayClosedClass.retryable; @@ -37,3 +87,25 @@ int? parseRateLimitRetrySeconds(String message) { final match = _rateLimitRetryPattern.firstMatch(message); return match == null ? null : int.tryParse(match.group(1)!); } + +/// Whether [value] has settled on a relay deadline. +/// +/// The forum periodic poll timers pause while a query is in this state; +/// reopening the view is the explicit retry. Other refresh paths (reconnect, +/// resume, live events, unread backstop) still re-send, each bounded by the +/// relay's 20s statement deadline. +bool isSettledRelayDeadline(AsyncValue value) => + value.hasError && !value.isLoading && isRelayDeadlineError(value.error!); + +/// Production Riverpod retry policy for relay providers. +/// +/// A relay statement deadline cannot resolve on retry — the same expensive +/// query would re-run and hit the same limit. Returns `null` (no retry) for +/// deadline errors and falls through to [ProviderContainer.defaultRetry] for +/// everything else. +/// +/// Pass this to [ProviderScope.retry] at the root of the widget tree. +Duration? relayProviderRetry(int retryCount, Object error) { + if (isRelayDeadlineError(error)) return null; + return ProviderContainer.defaultRetry(retryCount, error); +} diff --git a/mobile/lib/shared/relay/relay_session.dart b/mobile/lib/shared/relay/relay_session.dart index 51fb8bf51d..ece4b9266b 100644 --- a/mobile/lib/shared/relay/relay_session.dart +++ b/mobile/lib/shared/relay/relay_session.dart @@ -730,7 +730,12 @@ class RelaySessionNotifier extends Notifier { final liveSub = _liveSubscriptions[subId]; if (liveSub == null) return; final readyCompleter = liveSub.readyCompleter; - if (closedClass == RelayClosedClass.terminal) { + // A deadline is terminal for one-shot history, but a live subscription + // retries it: same filter under backoff, which can keep retrying at the + // cap. `since` is not advanced, so events missed while closed aren't + // skipped. + if (closedClass == RelayClosedClass.terminal && + !isRelayDeadlineError(message)) { if (readyCompleter != null && !readyCompleter.isCompleted) { readyCompleter.completeError(Exception(message)); } diff --git a/mobile/lib/shared/widgets/load_error_view.dart b/mobile/lib/shared/widgets/load_error_view.dart new file mode 100644 index 0000000000..50952e3cb8 --- /dev/null +++ b/mobile/lib/shared/widgets/load_error_view.dart @@ -0,0 +1,47 @@ +import 'package:flutter/material.dart'; +import 'package:lucide_icons_flutter/lucide_icons.dart'; + +import '../theme/theme.dart'; + +/// Settled load failure with an explicit Retry. After a relay deadline, +/// Riverpod does not auto-retry, so this is the user's way to re-send. +class LoadErrorView extends StatelessWidget { + final String message; + final VoidCallback onRetry; + + const LoadErrorView({ + super.key, + required this.message, + required this.onRetry, + }); + + @override + Widget build(BuildContext context) { + return Center( + child: Column( + mainAxisSize: MainAxisSize.min, + children: [ + Icon( + LucideIcons.triangleAlert, + size: Grid.lg, + color: context.colors.error, + ), + const SizedBox(height: Grid.xxs), + Text( + message, + style: context.textTheme.bodyMedium?.copyWith( + color: context.colors.onSurfaceVariant, + ), + ), + const SizedBox(height: Grid.xs), + FilledButton.icon( + key: const ValueKey('load-error-retry'), + onPressed: onRetry, + icon: const Icon(LucideIcons.refreshCcw, size: 16), + label: const Text('Retry'), + ), + ], + ), + ); + } +} diff --git a/mobile/test/features/channels/channel_detail_page_test.dart b/mobile/test/features/channels/channel_detail_page_test.dart index 20251f2195..4feaa96732 100644 --- a/mobile/test/features/channels/channel_detail_page_test.dart +++ b/mobile/test/features/channels/channel_detail_page_test.dart @@ -10187,6 +10187,62 @@ void main() { }); group('Error and loading states', () { + Widget errorScope(ChannelMessagesNotifier notifier) => ProviderScope( + overrides: [ + channelMessagesProvider(_channelId).overrideWith(() => notifier), + channelTypingProvider( + _channelId, + ).overrideWith(() => _FakeTypingNotifier([])), + userCacheProvider.overrideWith(() => _FakeUserCacheNotifier({})), + channelsProvider.overrideWith( + () => _FakeChannelsNotifier([_testChannel]), + ), + relayClientProvider.overrideWithValue( + RelayClient(baseUrl: 'http://localhost:3000'), + ), + savedPrefsProvider.overrideWithValue(_testPrefs), + ], + child: MaterialApp( + theme: AppTheme.light(), + home: ChannelDetailPage(channel: _testChannel), + ), + ); + final retry = find.byKey(const ValueKey('load-error-retry')); + + for (final (name, error) in [ + ( + 'deadline', + RelayException(503, '{"error":"query timed out"}') as Object, + ), + ('ordinary error', Exception('bridge down') as Object), + ]) { + testWidgets('Retry after a $name loads once', (tester) async { + final notifier = _RetryCountingMessagesNotifier( + () => AsyncError(error, StackTrace.current), + ); + await tester.pumpWidget(errorScope(notifier)); + await tester.pumpAndSettle(); + expect(find.text('Failed to load messages'), findsOneWidget); + expect(notifier.loads, 1); + final before = notifier.loads; + notifier.nextResult = () => const AsyncData([]); + await tester.tap(retry); + await tester.pumpAndSettle(); + expect(notifier.loads, before + 1); + expect(retry, findsNothing); + }); + } + + testWidgets('no Retry while messages load', (tester) async { + final notifier = _RetryCountingMessagesNotifier( + () => const AsyncLoading(), + ); + await tester.pumpWidget(errorScope(notifier)); + await tester.pump(); + expect(retry, findsNothing); + expect(find.text('Failed to load messages'), findsNothing); + }); + testWidgets('shows error message on failure', (tester) async { await tester.pumpWidget( ProviderScope( @@ -10891,6 +10947,225 @@ void main() { expect(highlightedDecoration.color!.a, lessThan(0.12)); }); + group('after a first-load deadline', () { + final root = _textMsg( + id: 'root', + pubkey: 'alice', + content: 'Thread root', + createdAt: 1000, + ); + final mid = _textMsg( + id: 'mid', + pubkey: 'bob', + content: 'Nested parent', + createdAt: 1100, + extraTags: const [ + ['e', 'root', '', 'reply'], + ], + ); + + Future<(_FakeMessagesNotifier, int Function())> openDeadlined( + WidgetTester tester, + NostrEvent head, + ) async { + var attempts = 0; + final messages = _FakeMessagesNotifier([root, mid]); + final timeline = formatTimeline([root, mid]); + await tester.pumpWidget( + _buildTestable( + messages: [root, mid], + messagesNotifier: messages, + disableRetries: true, + threadReplyLoaders: { + 'root': () { + attempts++; + return Future.error( + RelayException(503, '{"error":"query timed out"}'), + ); + }, + }, + home: ThreadDetailPage( + threadHead: timeline.firstWhere((m) => m.id == head.id), + allMessages: timeline, + channelId: _testChannel.id, + currentPubkey: 'me', + isMember: true, + isArchived: false, + ), + ), + ); + await tester.pumpAndSettle(); + expect(attempts, 1); + return (messages, () => attempts); + } + + NostrEvent liveReply(String id, List> tags) => _textMsg( + id: id, + pubkey: 'carol', + content: 'Live $id', + createdAt: 1200, + extraTags: tags, + ); + + testWidgets('shows an incoming direct reply', (tester) async { + final (messages, attempts) = await openDeadlined(tester, root); + messages.setMessages([ + root, + mid, + liveReply('direct', const [ + ['e', 'root', '', 'reply'], + ]), + ]); + await tester.pumpAndSettle(); + expect(find.text('Live direct'), findsOneWidget); + expect(find.textContaining('Couldn’t refresh'), findsOneWidget); + expect(attempts(), 1); + }); + + for (final provisional in [false, true]) { + testWidgets( + 'Retry ${provisional ? 'beside provisional replies' : 'in the empty state'} ' + 'loads once', + (tester) async { + // The empty variant has no reply at all, cached or provisional. + final seed = provisional ? [root, mid] : [root]; + final timeline = formatTimeline(seed); + var fail = true; + var loads = 0; + final messages = _FakeMessagesNotifier(seed); + await tester.pumpWidget( + _buildTestable( + messages: seed, + messagesNotifier: messages, + disableRetries: true, + threadReplyLoaders: { + 'root': () { + loads++; + if (!fail) return Future.value(const []); + return Future.error( + RelayException(503, '{"error":"query timed out"}'), + ); + }, + }, + home: ThreadDetailPage( + threadHead: timeline.firstWhere((m) => m.id == 'root'), + allMessages: timeline, + channelId: _testChannel.id, + currentPubkey: 'me', + isMember: true, + isArchived: false, + ), + ), + ); + await tester.pumpAndSettle(); + final retry = find.byKey(const ValueKey('thread-replies-retry')); + if (provisional) { + messages.setMessages([ + root, + mid, + liveReply('direct', const [ + ['e', 'root', '', 'reply'], + ]), + ]); + await tester.pumpAndSettle(); + expect(find.text('Live direct'), findsOneWidget); + } else { + expect(find.text('Couldn’t load replies'), findsOneWidget); + } + expect(retry, findsOneWidget); + final target = tester.getSize(retry); + expect( + target.width, + greaterThanOrEqualTo(kMinInteractiveDimension), + ); + expect( + target.height, + greaterThanOrEqualTo(kMinInteractiveDimension), + ); + final before = loads; + fail = false; + await tester.tap(retry); + await tester.pumpAndSettle(); + expect(loads, before + 1); + expect(retry, findsNothing); + }, + ); + } + + testWidgets('no replies Retry while the scan loads', (tester) async { + final timeline = formatTimeline([root, mid]); + await tester.pumpWidget( + _buildTestable( + messages: [root, mid], + threadReplyLoaders: { + 'root': () => Completer>().future, + }, + home: ThreadDetailPage( + threadHead: timeline.firstWhere((m) => m.id == 'root'), + allMessages: timeline, + channelId: _testChannel.id, + currentPubkey: 'me', + isMember: true, + isArchived: false, + ), + ), + ); + await tester.pump(); + await tester.pump(); + expect(find.textContaining('Couldn’t'), findsNothing); + expect( + find.byKey(const ValueKey('thread-replies-retry')), + findsNothing, + ); + }); + + testWidgets('shows an incoming nested reply', (tester) async { + final (messages, attempts) = await openDeadlined(tester, mid); + messages.setMessages([ + root, + mid, + liveReply('nested', const [ + ['e', 'root', '', 'root'], + ['e', 'mid', '', 'reply'], + ]), + ]); + await tester.pumpAndSettle(); + expect(find.text('Live nested'), findsOneWidget); + expect(attempts(), 1); + }); + + testWidgets('keeps a sent reply visible after acceptance', ( + tester, + ) async { + final (messages, attempts) = await openDeadlined(tester, root); + final sent = _textMsg( + id: 'sent', + pubkey: 'me', + content: 'My reply', + createdAt: 1300, + extraTags: const [ + ['e', 'root', '', 'reply'], + ], + ); + final container = ProviderScope.containerOf( + tester.element(find.byType(ThreadDetailPage)), + ); + const args = ThreadRepliesArgs(channelId: _channelId, rootId: 'root'); + container.read(threadLocalRepliesProvider(args).notifier).add(sent); + await tester.pumpAndSettle(); + expect(find.text('My reply'), findsOneWidget); + // Acceptance: the confirmed reply moves from the optimistic overlay + // into the channel cache (cacheConfirmedThreadReplies). + messages.setMessages([root, mid, sent]); + container.read(threadLocalRepliesProvider(args).notifier).confirm({ + 'sent', + }); + await tester.pumpAndSettle(); + expect(find.text('My reply'), findsOneWidget); + expect(attempts(), 1); + }); + }); + testWidgets('opens a nested reply in its direct-parent thread', ( tester, ) async { @@ -14650,6 +14925,23 @@ class _FakeMessagesNotifier extends ChannelMessagesNotifier { } } +/// Counts loads; each settles after mount, like the real network load. +class _RetryCountingMessagesNotifier extends ChannelMessagesNotifier { + _RetryCountingMessagesNotifier(this.nextResult) : super(_channelId); + + AsyncValue> Function() nextResult; + int loads = 0; + + @override + AsyncValue> build() { + loads++; + final result = nextResult(); + if (result is AsyncLoading) return result; + Future(() => state = result); + return const AsyncLoading(); + } +} + class _ErrorMessagesNotifier extends ChannelMessagesNotifier { _ErrorMessagesNotifier() : super(_channelId); diff --git a/mobile/test/features/channels/channel_messages_provider_test.dart b/mobile/test/features/channels/channel_messages_provider_test.dart index 729bf45fc7..bc6f1dab1d 100644 --- a/mobile/test/features/channels/channel_messages_provider_test.dart +++ b/mobile/test/features/channels/channel_messages_provider_test.dart @@ -312,6 +312,57 @@ void main() { ); }); + group('relay deadline owners', () { + RelayException deadline() => + RelayException(503, '{"error":"query timed out"}'); + int threadScans(_RecordingRelaySessionNotifier session) => session + .queryFilters + .where((filter) => filter.extensions.containsKey('depth_limit')) + .length; + NostrEvent reply(int i) => _event( + id: 'reply-$i', + createdAt: 20 + i, + extraTags: const [ + ['e', 'root', '', 'reply'], + ], + ); + + test('a window deadline does not fall back to websocket history', () async { + final session = _RecordingRelaySessionNotifier( + queryResults: [deadline()], + ); + final container = _buildContainer(session); + addTearDown(container.dispose); + container.listen(channelMessagesProvider(_channelId), (_, _) {}); + await session.subscribed; + await _pumpEventQueue(); + expect(session.operations, ['subscribe', 'query']); + expect( + container.read(channelMessagesProvider(_channelId)).hasError, + true, + ); + }); + + test('a recount deadline ends its retry backoff', () async { + final session = _RecordingRelaySessionNotifier( + queryResults: [ + [_event(id: 'root', createdAt: 10), _bounds()], + deadline(), + deadline(), + ], + ); + final container = _buildContainer(session); + addTearDown(container.dispose); + container.listen(channelMessagesProvider(_channelId), (_, _) {}); + await _pumpEventQueue(); + for (var i = 0; i < 300; i++) { + session.emit(reply(i)); + } + await Future.delayed(const Duration(milliseconds: 2000)); + expect(threadScans(session), 1); + }); + }); + test('still loads history when live subscription fails', () async { final relaySession = _RecordingRelaySessionNotifier(failSubscribe: true); final container = _buildContainer(relaySession); diff --git a/mobile/test/features/channels/channels_provider_test.dart b/mobile/test/features/channels/channels_provider_test.dart index 3bb1be5beb..e277a4dfb3 100644 --- a/mobile/test/features/channels/channels_provider_test.dart +++ b/mobile/test/features/channels/channels_provider_test.dart @@ -1632,6 +1632,168 @@ void main() { expect(channels.single.lastMessageAt?.millisecondsSinceEpoch, 20 * 1000); }); + group('latest-message batch failure', () { + Future> fallbackFilters(Object error) async { + final session = _FakeRelaySession( + memberships: [_membership(_channelA, myPk)], + metadata: [_meta(id: _channelA, name: 'general')], + )..messageBatchError = error; + final container = _buildContainer(session: session); + addTearDown(container.dispose); + await container.read(channelsProvider.future); + await _waitUntil(() => session.queryBatches.isNotEmpty); + await Future.delayed(Duration.zero); + return session.historyFilters + .where( + (filter) => + filter.kinds.contains(EventKind.streamMessageV2) && + (filter.tags['#h']?.contains(_channelA) ?? false), + ) + .toList(); + } + + test('a relay deadline never reaches the websocket fallback', () async { + expect( + await fallbackFilters( + RelayException(503, '{"error":"query timed out"}'), + ), + isEmpty, + ); + }); + + test('an ordinary failure still uses the websocket fallback', () async { + expect(await fallbackFilters(Exception('bridge down')), isNotEmpty); + }); + }); + + group('deadline-unavailable channel batches', () { + Object deadline() => RelayException(503, '{"error":"query timed out"}'); + bool isUnread(List batch) => + batch.isNotEmpty && batch.every((filter) => filter.since != null); + NostrEvent message(String id, int createdAt, {bool mention = false}) => + NostrEvent( + id: id, + pubkey: 'alice', + createdAt: createdAt, + kind: EventKind.streamMessageV2, + tags: [ + const ['h', _channelA], + if (mention) const ['p', myPk], + ], + content: 'hi', + sig: 'sig', + ); + + test('a latest-message deadline keeps known timestamps', () async { + final session = _FakeRelaySession( + memberships: [_membership(_channelA, myPk)], + metadata: [_meta(id: _channelA, name: 'general')], + recentMessages: [message('m1', 30)], + ); + final container = _buildContainer(session: session); + addTearDown(container.dispose); + await container.read(channelsProvider.future); + await _settle(); + session.latestBatchError = deadline(); + await container.read(channelsProvider.notifier).refresh(); + await _settle(); + expect( + container.read(channelsProvider).value!.single.lastMessageAt, + DateTime.fromMillisecondsSinceEpoch(30 * 1000, isUtc: true), + ); + expect(session.messageHistoryCount, 0); + }); + + test( + 'a cold-start latest-message deadline is filled by unread catch-up', + () async { + final session = _FakeRelaySession( + memberships: [_membership(_channelA, myPk)], + metadata: [_meta(id: _channelA, name: 'general')], + recentMessages: [message('mention', 30, mention: true)], + )..latestBatchError = deadline(); + final container = _buildContainer(session: session); + addTearDown(container.dispose); + await container.read(channelsProvider.future); + await _waitUntil(() => session.queryBatches.any(isUnread)); + await _settle(); + final notifier = container.read(channelsProvider.notifier); + expect(notifier.observedUnreadEventsByChannel[_channelA]?.keys, [ + 'mention', + ]); + expect( + container.read(channelsProvider).value!.single.lastMessageAt, + DateTime.fromMillisecondsSinceEpoch(30 * 1000, isUtc: true), + ); + expect(session.messageHistoryCount, 0); + }, + ); + + test('unread catch-up never moves lastMessageAt backward', () async { + final session = _FakeRelaySession( + memberships: [_membership(_channelA, myPk)], + metadata: [_meta(id: _channelA, name: 'general')], + recentMessages: [message('older', 30, mention: true)], + )..pauseNextUnreadCatchUpQuery(); + final container = _buildContainer(session: session); + addTearDown(container.dispose); + await container.read(channelsProvider.future); + await session.nextUnreadCatchUpQueryStarted; + // A newer live event lands while the catch-up is in flight. + session.emit(message('newer', 60, mention: true)); + session.resumePausedUnreadCatchUpQuery(); + await _settle(); + expect( + container + .read(channelsProvider.notifier) + .observedUnreadEventsByChannel[_channelA] + ?.keys, + containsAll(['older', 'newer']), + ); + expect( + container.read(channelsProvider).value!.single.lastMessageAt, + DateTime.fromMillisecondsSinceEpoch(60 * 1000, isUtc: true), + ); + }); + + // HTTP fails ordinarily, then a per-filter websocket fallback times out: + // the batch is unavailable and no later chunk is sent. + test('a websocket fallback deadline makes the batch unavailable', () async { + final ids = [for (var i = 0; i < 6; i++) 'chunk-channel-$i']; + final session = _FakeRelaySession( + memberships: [ + _membership(_channelA, myPk), + for (final id in ids) _membership(id, myPk), + ], + metadata: [ + _meta(id: _channelA, name: 'general'), + for (final id in ids) _meta(id: id, name: id), + ], + recentMessages: [message('m1', 30)], + ); + final container = _buildContainer(session: session); + addTearDown(container.dispose); + await container.read(channelsProvider.future); + await _settle(); + general() => container + .read(channelsProvider) + .value! + .firstWhere((channel) => channel.id == _channelA); + final lastMessageAt = general().lastMessageAt; + expect(lastMessageAt, isNotNull); + session + ..messageBatchError = Exception('bridge down') + ..messageHistoryError = deadline(); + await container.read(channelsProvider.notifier).refresh(); + await _settle(); + // Unavailable, not empty: known timestamps survive. + expect(general().lastMessageAt, lastMessageAt); + // Each batch stops after its first chunk of four filters. + expect(session.messageHistoryCount % 4, 0); + expect(session.messageHistoryCount, lessThan(2 * ids.length)); + }); + }); + test( 'loads all channel timestamps through one batched relay query', () async { @@ -2261,6 +2423,11 @@ class _FakeRelaySession extends RelaySessionNotifier { final List historyFilters = []; final List> queryBatches = []; + Object? messageBatchError; + Object? latestBatchError; + Object? messageHistoryError; + int messageHistoryCount = 0; + final List directoryQueryFilters = []; final List membershipQueryFilters = []; final List subscribeFilters = []; @@ -2536,6 +2703,9 @@ class _FakeRelaySession extends RelaySessionNotifier { // Member metadata query — return only matching `d` tags. return metadata.where((e) => ids.contains(e.getTagValue('d'))).toList(); } + // Per-filter websocket fallback of a message batch. + messageHistoryCount++; + if (messageHistoryError case final error?) throw error; return const []; } @@ -2614,11 +2784,13 @@ class _FakeRelaySession extends RelaySessionNotifier { return filter.until == null ? directorySnapshot : const []; } queryBatches.add(filters); + if (messageBatchError case final error?) throw error; // The unread catch-up is the only batch that carries `since` on every // filter; the latest-message batch leaves it null. Snapshot the messages at // request time so a parked response reflects the scope that asked for it. final isUnreadCatchUp = filters.isNotEmpty && filters.every((filter) => filter.since != null); + if (!isUnreadCatchUp && latestBatchError != null) throw latestBatchError!; final messageSnapshot = List.of(recentMessages); if (isUnreadCatchUp) { // Claim the parked slot so the refresh that follows the switch can run diff --git a/mobile/test/features/forum/forum_widgets_test.dart b/mobile/test/features/forum/forum_widgets_test.dart index 2d22026530..690ada9317 100644 --- a/mobile/test/features/forum/forum_widgets_test.dart +++ b/mobile/test/features/forum/forum_widgets_test.dart @@ -1,3 +1,5 @@ +import 'dart:async'; + import 'package:flutter/material.dart'; import 'package:flutter_test/flutter_test.dart'; import 'package:hooks_riverpod/hooks_riverpod.dart'; @@ -164,6 +166,56 @@ Widget _buildThreadPage({ ); } +class _CountingForumSession extends RelaySessionNotifier { + _CountingForumSession(this.error); + + Object? error; + int fetchCount = 0; + Completer? park; + + /// Forum-surface attempts only: the posts list (45001) or thread replies + /// (`#e`), excluding shared sub-providers such as profiles and emoji. + int forumAttempts = 0; + + @override + SessionState build() => const SessionState(status: SessionStatus.connected); + + @override + Future> fetchHistory( + NostrFilter filter, { + Duration timeout = const Duration(seconds: 8), + }) async { + fetchCount++; + if (filter.ids == null && + (filter.kinds.contains(45001) || filter.tags.containsKey('#e'))) { + forumAttempts++; + if (park case final park?) await park.future; + } + if (error case final error?) throw error; + return const []; + } +} + +Widget _buildLiveForum(_CountingForumSession session, Widget child) => + ProviderScope( + // Isolate the timers from Riverpod's own error retry. + retry: (_, _) => null, + overrides: [ + relaySessionProvider.overrideWith(() => session), + userCacheProvider.overrideWith(() => _FakeUserCacheNotifier(const {})), + knownAgentPubkeysProvider.overrideWithValue(const {}), + profileProvider.overrideWith(() => _FakeProfileNotifier()), + savedPrefsProvider.overrideWithValue(_testPrefs), + relayClientProvider.overrideWithValue( + RelayClient(baseUrl: 'http://localhost:3000'), + ), + ], + child: MaterialApp( + theme: AppTheme.light(), + home: Scaffold(body: child), + ), + ); + void main() { setUp(() async { SharedPreferences.setMockInitialValues({}); @@ -194,6 +246,134 @@ void main() { ); }); + group('forum polling after a relay deadline', () { + final deadline = RelayException(503, '{"error":"query timed out"}'); + final surfaces = { + 'posts view (15s)': ( + ForumPostsView(channel: _forumChannel, currentPubkey: 'self'), + const Duration(seconds: 15), + ), + 'thread page (10s)': ( + const ForumThreadPage( + channelId: _channelId, + postEventId: 'post1', + currentPubkey: 'self', + isMember: true, + isArchived: false, + ), + const Duration(seconds: 10), + ), + }; + for (final MapEntry(key: name, value: (surface, interval)) + in surfaces.entries) { + testWidgets('$name pauses on a deadline', (tester) async { + final session = _CountingForumSession(deadline); + await tester.pumpWidget(_buildLiveForum(session, surface)); + await tester.pump(); + final settled = session.fetchCount; + expect(session.forumAttempts, 1); + for (var tick = 0; tick < 4; tick++) { + await tester.pump(interval); + } + expect(session.fetchCount, settled); + await tester.pumpWidget(const SizedBox()); + }); + + testWidgets('$name keeps polling after an ordinary error', ( + tester, + ) async { + final session = _CountingForumSession(Exception('reset')); + await tester.pumpWidget(_buildLiveForum(session, surface)); + await tester.pump(); + final settled = session.fetchCount; + await tester.pump(interval); + await tester.pump(); + expect(session.fetchCount, greaterThan(settled)); + await tester.pumpWidget(const SizedBox()); + }); + + for (final (kind, error) in [ + ('deadline', deadline as Object), + ('ordinary error', Exception('reset') as Object), + ]) { + testWidgets('$name Retry after a $kind loads once', (tester) async { + final session = _CountingForumSession(error); + await tester.pumpWidget(_buildLiveForum(session, surface)); + await tester.pump(); + await tester.pump(); + final retry = find.byKey(const ValueKey('load-error-retry')); + expect(retry, findsOneWidget); + final before = session.forumAttempts; + session.error = null; + await tester.tap(retry); + await tester.pump(); + await tester.pump(); + expect(session.forumAttempts, before + 1); + // The post list settles empty; the thread page has no fake post, + // so it settles on not-found again (the count shows the reload). + if (surface is ForumPostsView) expect(retry, findsNothing); + await tester.pumpWidget(const SizedBox()); + }); + + testWidgets('$name hides Retry while a $kind retry is pending', ( + tester, + ) async { + final session = _CountingForumSession(error); + await tester.pumpWidget(_buildLiveForum(session, surface)); + await tester.pump(); + await tester.pump(); + final retry = find.byKey(const ValueKey('load-error-retry')); + expect(retry, findsOneWidget); + final before = session.forumAttempts; + final park = session.park = Completer(); + await tester.tap(retry); + await tester.pump(); + await tester.pump(); + expect(retry, findsNothing); + expect(session.forumAttempts, before + 1); + // The replacement fails the same way and settles on Retry again. + park.complete(); + await tester.pump(); + await tester.pump(); + expect(retry, findsOneWidget); + expect(session.forumAttempts, before + 1); + await tester.pumpWidget(const SizedBox()); + }); + } + + testWidgets('$name shows no Retry while loading', (tester) async { + final session = _CountingForumSession(deadline) + ..park = Completer(); + await tester.pumpWidget(_buildLiveForum(session, surface)); + await tester.pump(); + expect(session.forumAttempts, 1); + expect(find.byKey(const ValueKey('load-error-retry')), findsNothing); + session.park!.complete(); + await tester.pump(); + await tester.pump(); + expect(find.byKey(const ValueKey('load-error-retry')), findsOneWidget); + await tester.pumpWidget(const SizedBox()); + }); + + testWidgets('$name reopening retries a deadline', (tester) async { + final session = _CountingForumSession(deadline); + await tester.pumpWidget(_buildLiveForum(session, surface)); + await tester.pump(); + expect(session.forumAttempts, 1); + await tester.pumpWidget(_buildLiveForum(session, const SizedBox())); + await tester.pumpWidget(_buildLiveForum(session, surface)); + await tester.pump(); + await tester.pump(); + expect(session.forumAttempts, 2); + for (var tick = 0; tick < 4; tick++) { + await tester.pump(interval); + } + expect(session.forumAttempts, 2); + await tester.pumpWidget(const SizedBox()); + }); + } + }); + group('ForumPostCard', () { testWidgets('renders author name and content', (tester) async { await tester.pumpWidget( diff --git a/mobile/test/shared/relay/relay_closed_policy_test.dart b/mobile/test/shared/relay/relay_closed_policy_test.dart index ff78ea89ef..d83f658f40 100644 --- a/mobile/test/shared/relay/relay_closed_policy_test.dart +++ b/mobile/test/shared/relay/relay_closed_policy_test.dart @@ -16,6 +16,7 @@ void main() { 'unsupported: filter extension': RelayClosedClass.terminal, 'error: mixed search and channel filter': RelayClosedClass.terminal, 'error: too many subscriptions': RelayClosedClass.terminal, + 'error: query timed out': RelayClosedClass.terminal, 'error: relay temporarily unavailable': RelayClosedClass.retryable, 'subscription closed by relay': RelayClosedClass.retryable, }; diff --git a/mobile/test/shared/relay/relay_deadline_provider_retry_test.dart b/mobile/test/shared/relay/relay_deadline_provider_retry_test.dart new file mode 100644 index 0000000000..c2b53103c0 --- /dev/null +++ b/mobile/test/shared/relay/relay_deadline_provider_retry_test.dart @@ -0,0 +1,226 @@ +import 'dart:async'; + +import 'package:buzz/features/channels/thread_replies_provider.dart'; +import 'package:buzz/features/forum/forum_provider.dart'; +import 'package:buzz/main.dart'; +import 'package:buzz/shared/relay/relay.dart'; +import 'package:flutter/widgets.dart'; +import 'package:flutter_test/flutter_test.dart'; +import 'package:hooks_riverpod/hooks_riverpod.dart'; +import 'package:shared_preferences/shared_preferences.dart'; + +// --------------------------------------------------------------------------- +// Fake sessions +// --------------------------------------------------------------------------- + +class _DeadlineHttpSession extends RelaySessionNotifier { + int queryCount = 0; + + @override + SessionState build() => const SessionState(status: SessionStatus.connected); + + @override + Future> queryRelay( + List filters, { + Duration timeout = const Duration(seconds: 8), + }) async { + queryCount++; + // Relay HTTP 503 with JSON body: {"error":"query timed out"} + throw RelayException(503, '{"error":"query timed out"}'); + } +} + +class _DeadlineWsSession extends RelaySessionNotifier { + int historyCount = 0; + + @override + SessionState build() => const SessionState(status: SessionStatus.connected); + + @override + Future> fetchHistory( + NostrFilter filter, { + Duration timeout = const Duration(seconds: 8), + }) async { + historyCount++; + // WebSocket CLOSED: Exception("error: query timed out") + throw Exception('error: query timed out'); + } +} + +class _OrdinaryErrorSession extends RelaySessionNotifier { + int queryCount = 0; + + @override + SessionState build() => const SessionState(status: SessionStatus.connected); + + @override + Future> queryRelay( + List filters, { + Duration timeout = const Duration(seconds: 8), + }) async { + queryCount++; + throw RelayException(500, '{"error":"internal server error"}'); + } + + @override + Future> fetchHistory( + NostrFilter filter, { + Duration timeout = const Duration(seconds: 8), + }) async { + queryCount++; + throw RelayException(500, '{"error":"internal server error"}'); + } +} + +// --------------------------------------------------------------------------- +// isRelayDeadlineError unit tests +// --------------------------------------------------------------------------- + +void main() { + test('the production root scope uses relayProviderRetry', () async { + SharedPreferences.setMockInitialValues({}); + final scope = buildRootProviderScope( + prefs: await SharedPreferences.getInstance(), + child: const SizedBox(), + ); + expect(scope.retry, same(relayProviderRetry)); + }); + + group('isRelayDeadlineError', () { + test('matches HTTP 503 query timed out', () { + expect( + isRelayDeadlineError( + RelayException(503, '{"error":"query timed out"}'), + ), + isTrue, + ); + }); + + test('matches HTTP 503 with whitespace in body value', () { + expect( + isRelayDeadlineError( + RelayException(503, '{"error":" Query Timed Out "}'), + ), + isTrue, + ); + }); + + test('does not match HTTP 503 with different error', () { + expect( + isRelayDeadlineError( + RelayException(503, '{"error":"service unavailable"}'), + ), + isFalse, + ); + }); + + test('does not match HTTP 503 with non-JSON body', () { + expect(isRelayDeadlineError(RelayException(503, 'plain text')), isFalse); + }); + + test('does not match HTTP 500', () { + expect( + isRelayDeadlineError( + RelayException(500, '{"error":"query timed out"}'), + ), + isFalse, + ); + }); + + test('matches WebSocket CLOSED exception string', () { + expect(isRelayDeadlineError(Exception('error: query timed out')), isTrue); + }); + + test('does not match ordinary exception', () { + expect(isRelayDeadlineError(Exception('connection refused')), isFalse); + }); + + test('does not match TimeoutException', () { + expect( + isRelayDeadlineError( + TimeoutException( + 'Relay history request timed out after 0:00:08.000000', + ), + ), + isFalse, + ); + }); + }); + + // ------------------------------------------------------------------------- + // threadRepliesProvider — HTTP path + // ------------------------------------------------------------------------- + + group('threadRepliesProvider deadline retry suppression', () { + const args = ThreadRepliesArgs(channelId: 'chan', rootId: 'root'); + + test( + 'deadline: settles error in exactly one call and does not rebuild', + () async { + final session = _DeadlineHttpSession(); + final container = ProviderContainer( + retry: relayProviderRetry, + overrides: [relaySessionProvider.overrideWith(() => session)], + ); + addTearDown(container.dispose); + + final sub = container.listen(threadRepliesProvider(args), (_, _) {}); + addTearDown(sub.close); + + await container.pump(); + await Future.delayed(const Duration(milliseconds: 500)); + + expect(container.read(threadRepliesProvider(args)).hasError, isTrue); + expect(session.queryCount, 1); + }, + ); + + test( + 'ordinary error: retries at least once with production retry policy', + () async { + final session = _OrdinaryErrorSession(); + final container = ProviderContainer( + retry: relayProviderRetry, + overrides: [relaySessionProvider.overrideWith(() => session)], + ); + addTearDown(container.dispose); + + final sub = container.listen(threadRepliesProvider(args), (_, _) {}); + addTearDown(sub.close); + + await container.pump(); + await Future.delayed(const Duration(milliseconds: 400)); + + // At least 2 calls means Riverpod issued at least one retry. + expect(session.queryCount, greaterThanOrEqualTo(2)); + }, + ); + }); + + // ------------------------------------------------------------------------- + // forumPostsProvider — WebSocket history path + // ------------------------------------------------------------------------- + + group('forumPostsProvider deadline retry suppression', () { + test( + 'deadline: settles error in exactly one call and does not rebuild', + () async { + final session = _DeadlineWsSession(); + final container = ProviderContainer( + retry: relayProviderRetry, + overrides: [relaySessionProvider.overrideWith(() => session)], + ); + addTearDown(container.dispose); + + final sub = container.listen(forumPostsProvider('chan'), (_, _) {}); + addTearDown(sub.close); + + await container.pump(); + await Future.delayed(const Duration(milliseconds: 500)); + + expect(container.read(forumPostsProvider('chan')).hasError, isTrue); + expect(session.historyCount, 1); + }, + ); + }); +} diff --git a/mobile/test/shared/relay/relay_session_test.dart b/mobile/test/shared/relay/relay_session_test.dart index 413f12a82e..50bdb5201d 100644 --- a/mobile/test/shared/relay/relay_session_test.dart +++ b/mobile/test/shared/relay/relay_session_test.dart @@ -1100,6 +1100,38 @@ void main() { expect(_reqs(socket).where((req) => req[1] == 'l-1'), hasLength(1)); }); + test('a deadline CLOSED retries a live sub but fails history', () async { + final timers = <_ManualTimer>[]; + final socket = _RecordingRelaySocket(); + final statuses = []; + final session = RelaySessionNotifier( + retryTimerFactory: (duration, callback) { + final timer = _ManualTimer(duration, callback); + timers.add(timer); + return timer; + }, + ); + session.debugAttachSocketForTest(socket); + final subscribe = session.subscribeWithStatus( + _channelFilter, + (_) {}, + onStatusChanged: statuses.add, + ); + session.debugHandleMessage(['EOSE', 'l-1']); + await subscribe; + + session.debugHandleMessage(['CLOSED', 'l-1', 'error: query timed out']); + expect(statuses.last, RelaySubscriptionStatus.retrying); + timers.single.fire(); + await Future.delayed(Duration.zero); + expect(_reqs(socket).where((req) => req[1] == 'l-1'), hasLength(2)); + + final history = session.fetchHistory(_channelFilter); + final historyId = _reqs(socket).last[1] as String; + session.debugHandleMessage(['CLOSED', historyId, 'error: query timed out']); + await expectLater(history, throwsA(isA())); + }); + test('unsubscribe and dispose cancel CLOSED retry timers', () async { final timers = <_ManualTimer>[]; final socket = _RecordingRelaySocket(); diff --git a/schema/schema.sql b/schema/schema.sql index fdd382f463..37112cc670 100644 --- a/schema/schema.sql +++ b/schema/schema.sql @@ -278,6 +278,10 @@ CREATE INDEX idx_events_not_before ON events (community_id, not_before) -- EXPLAIN before its work lands (Quinn option A; Max's index-spelling caveat). CREATE INDEX idx_events_search_tsv ON events USING GIN (search_tsv); +-- e-tag containment (`tags @> '[["e",""]]'`) for the aux closure and #e +-- reads. Mirrors migrations/0004; jsonb_path_ops supports exactly @>. +CREATE INDEX idx_events_tags_gin ON events USING GIN (tags jsonb_path_ops); + -- ── Event mentions ──────────────────────────────────────────────────────────── -- Conformance: "Channel-less global events and DMs" (#p fan-out). The join to -- events MUST carry the community tuple (e.community_id = m.community_id AND diff --git a/scripts/run-tests.sh b/scripts/run-tests.sh index 32bfa1c94b..ff18a07fd1 100755 --- a/scripts/run-tests.sh +++ b/scripts/run-tests.sh @@ -157,7 +157,7 @@ run_unit_tests() { # Mirror the relay filters from `just test-unit`: the three handler modules, # storage-snapshot helpers, readiness and router unit suites, and the single - # scoped admission regression in state::tests. + # scoped admission regression in state::tests, plus the REQ lifecycle tests. run_test_step "buzz-relay channel authorization tests" \ cargo test -p buzz-relay --lib handlers::channel_authz:: -- --nocapture @@ -170,6 +170,20 @@ run_unit_tests() { run_test_step "buzz-relay storage snapshot tests" \ cargo test -p buzz-relay --lib storage_sweep::tests:: -- --nocapture + # Infra-free REQ subscription-lifecycle tests, by exact name: the rest of + # handlers::req needs a database. + run_test_step "buzz-relay REQ subscription lifecycle tests" \ + cargo test -p buzz-relay --lib -- --exact --nocapture \ + handlers::req::tests::timed_out_historical_read_deregisters_before_closed \ + handlers::req::tests::superseded_timeout_leaves_replacement_intact \ + handlers::req::tests::search_claim_retires_live_and_yields_to_replacement \ + handlers::req::tests::concurrent_claims_and_stale_teardowns_keep_the_last_owner \ + handlers::req::tests::timeout_closed_is_emitted_before_a_replacement_can_claim \ + handlers::req::tests::revoke_then_replacement_keeps_replacement_whole \ + handlers::req::tests::claims_after_connection_cleanup_are_refused \ + handlers::req::tests::dropped_terminal_frame_cancels_connection \ + handlers::req::tests::revoke_dropped_terminal_frame_cancels_connection + run_test_step "buzz-relay readiness tests" \ cargo test -p buzz-relay --lib readiness::tests:: -- --nocapture diff --git a/scripts/seed-long-thread.sh b/scripts/seed-long-thread.sh new file mode 100755 index 0000000000..70e0d18297 --- /dev/null +++ b/scripts/seed-long-thread.sh @@ -0,0 +1,62 @@ +#!/usr/bin/env bash +# Seed one long thread on the local dev relay, for reproducing and eyeballing +# long-thread loading in the apps. +# +# just relay # stock local relay on ws://localhost:3000 +# just seed-long-thread 187 # or: scripts/seed-long-thread.sh [replies] +# +# Targets SEED_RELAY_URL (default: .env RELAY_URL, else ws://localhost:3000) +# and refuses non-loopback relays. Ambient BUZZ_RELAY_URL/BUZZ_PRIVATE_KEY are +# ignored so an agent or shell session can never seed its real relay. Posts +# with SEED_PRIVATE_KEY (default: a fresh throwaway key) into a new open stream +# channel, or into SEED_CHANNEL if that key may post there. +# +# Every write (channel, root, replies, reactions) counts against the relay's +# 60 human messages/min, so writes are paced SEED_DELAY seconds apart (default +# 1.05): the default run takes ~3-4 minutes on a stock relay. Set SEED_DELAY=0 +# when BUZZ_RATE_LIMIT_HUMAN_MESSAGES_PER_MIN is raised on the relay. +set -euo pipefail + +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +REPO_ROOT="$(cd "${SCRIPT_DIR}/.." && pwd)" +cd "${REPO_ROOT}" + +if [[ -f ".env" ]]; then + set -o allexport + # shellcheck disable=SC1091 + source .env + set +o allexport +fi + +REPLIES="${1:-187}" +REACTIONS="${SEED_REACTIONS:-20}" +export BUZZ_RELAY_URL="${SEED_RELAY_URL:-${RELAY_URL:-ws://localhost:3000}}" +export BUZZ_PRIVATE_KEY="${SEED_PRIVATE_KEY:-$(openssl rand -hex 32)}" +unset BUZZ_AUTH_TAG +if [[ ! "$BUZZ_RELAY_URL" =~ ^wss?://(localhost|127\.0\.0\.1|\[::1\])(:[0-9]+)?/?$ ]]; then + echo "refusing non-local relay: $BUZZ_RELAY_URL" >&2 + exit 1 +fi +BUZZ="${BUZZ_CLI:-cargo run -q -p buzz-cli --}" +DELAY="${SEED_DELAY:-1.05}" +write() { $BUZZ "$@"; sleep "$DELAY"; } + +channel="${SEED_CHANNEL:-}" +if [[ -z "$channel" ]]; then + channel="$(write channels create --name "long-thread-$$" --type stream --visibility open | jq -er .channel_id)" +fi +root="$(write messages send --channel "$channel" --content "long thread root ($REPLIES replies)" | jq -er .event_id)" + +ids=() +for i in $(seq 1 "$REPLIES"); do + ids+=("$(write messages send --channel "$channel" --reply-to "$root" --content "reply $i" | jq -er .event_id)") +done +if (( REPLIES > 0 )); then + for i in $(seq 1 "$REACTIONS"); do + write reactions add --event "${ids[$(( (i * 7) % REPLIES ))]}" --emoji "👍" >/dev/null + done +fi + +echo "channel=$channel" +echo "root=$root" +echo "replies=$REPLIES reactions=$(( REPLIES > 0 ? REACTIONS : 0 ))"