From 85996fdff49191f0f999d50bad201d4ef60e8d69 Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Tue, 10 Nov 2026 08:40:29 +1100 Subject: [PATCH] test: fix timing-dependent unit tests in buzz-cli, buzz-agent and buzz-admin (#9273) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Summary Split out of the `flakey-monday` flake-fix series. Three Rust unit tests in `buzz-cli`, `buzz-agent` and `buzz-admin` depended on wall-clock timing or on a production-sized pool budget and failed on loaded CI runners. Each now waits on, or counts, the thing it actually asserts. Commits (cherry-picked from `flakey-monday`, original messages kept): - `test(cli): throttle the first desktop sign-in by count, not clock` - `test(agent): wait for both responses in steer_rejected_on_empty_prompt` - `test(agent): pin steer_rejected_on_empty_prompt to the empty-prompt guard` - `test(admin): give the NIP-FI Postgres tests a test-lane pool budget` ### Root cause and fix per test **`client::desktop_throttle_tests::a_throttled_sign_in_reconnects_with_fresh_evidence`** (`crates/buzz-cli/src/client.rs`): failed once in CI with `conns` left 1, right 2. - Root cause (confirmed): the fake desktop throttled a sign-in only when `last.elapsed() < 300ms`, and `last` was captured before the provider handshake and credential setup. When that setup took over 300 ms, the first sign-in was signed straight away, nothing was throttled, the client never reconnected, and the relay saw one connection. - Fix: the fake desktop throttles exactly its first `sign_event` call via an atomic counter, which is the scenario the test describes. The relay's unsigned-socket deadline goes from 200 ms to 5 s, as in the sibling deadline tests, so it no longer shapes the scenario. Assertions are unchanged: two connections, only "c1" signed, a fresh assertion on the reconnect. **`steer_rejected_on_empty_prompt`** (`crates/buzz-agent/tests/fake_llm.rs`): panicked with "empty steer prompt was not rejected". - Root cause (confirmed): `session/prompt` runs in a spawned task while `_goose/unstable/session/steer` is answered inline from the stdin loop. The fake LLM finishes the turn almost at once, so the prompt response can arrive before the agent has read the steer. The receive loop broke on the prompt response and never saw the steer's -32602. - Fix: keep reading, bounded at 40 messages as before, until both the steer and prompt responses have arrived in either order. The follow-up commit also asserts `error.message == "steer: prompt must not be empty"`, because `steer_session` returns -32602 for "no active run to steer" and an `expectedRunId` mismatch too, which are exactly the replies a steer gets when the turn ends first. The empty-prompt check runs right after decoding, so the message is deterministic in both orderings. **`nip_fi::postgres_tests::{backfill_binds_only_bindable_hosts_and_reports_the_rest, backfill_skips_a_community_being_deleted, bind_refuses_hosts_outside_the_suffix_and_unbind_keeps_the_last_issuer}`** (`crates/buzz-admin/src/nip_fi.rs`): `connect to test DB: Sqlx(PoolTimedOut)` after about 3.5 s. - Root cause (confirmed): the tests built their pool from `DbConfig::default()`, sized for a warm relay pod (3 s acquire timeout, two eager spare connections). In the first wave of the PostgreSQL lane every nextest worker clones its database from the template at once, so a first connection can take longer than 3 s. - Fix: keep the production writer pool (`Db::new`, so the session policy is still exercised) but set `min_connections` 0 and a 30 s acquire timeout, the budget sqlx's `PgPool::connect` defaults give the other PostgreSQL tests. `Db::connect_cold_start` uses the same values. ### Related issue N/A (flake fixes; none found). ### Testing Human testing is still required. This PR does not carry `buzz-review-completed`; the author has not yet run these tests themselves on this branch. #### Verification These changes were verified locally on the `flakey-monday` branch before the split: - buzz-cli throttle test: old code under CPU saturation (40 busy loops on 32 cores) failed every iteration with `left: 1`, the CI failure. New code, `desktop_throttle_tests` with `--test-threads=16`: 30/30 passed unloaded, 15/15 under the same saturation. - buzz-agent steer test: forced CI ordering (temporary 500 ms delay before sending the steer) made the old test panic and the new test pass. `fake_llm steer` tests with `--test-threads=16`: 30/30 passed. The follow-up ran 100/100, and was falsified: with the empty-prompt guard removed and the steer sent after the turn, the code check still passed and the new message assertion failed. - buzz-admin NIP-FI tests, against docker Postgres: the three tests, 10 iterations at `--test-threads=3`: 10/10. Behind a proxy delaying each new connection by 4 s: the old config failed with the CI `PoolTimedOut` at 3 s, the new config passed. Note: `crates/buzz-cli/src/client.rs` also changed on `main` since the series forked. The cherry-pick applied cleanly; only hunk offsets differ from the original commit. Nothing was re-run on this split branch: the workstation was overloaded, so no tests, builds or linters were executed after cherry-picking. CI on this PR is the verification for the split branch. 🤖 Generated with [Claude Code](https://claude.com/claude-code) --------- Signed-off-by: mtoohey Co-authored-by: Claude Opus 5.5 --- crates/buzz-admin/src/nip_fi.rs | 7 +++++++ crates/buzz-agent/tests/fake_llm.rs | 30 ++++++++++++++++++++++------- crates/buzz-cli/src/client.rs | 22 +++++++++++---------- 3 files changed, 42 insertions(+), 17 deletions(-) diff --git a/crates/buzz-admin/src/nip_fi.rs b/crates/buzz-admin/src/nip_fi.rs index 75eed82202..dd9a4867ec 100644 --- a/crates/buzz-admin/src/nip_fi.rs +++ b/crates/buzz-admin/src/nip_fi.rs @@ -277,11 +277,18 @@ mod postgres_tests { const ISS: &str = "https://issuer.example/api/goose"; + /// The production writer pool, with the connection budget of the sqlx + /// pools the other PostgreSQL tests use. The relay's 3 s acquire timeout + /// and two eager spare connections are sized for a warm relay pod, not for + /// the first wave of a test lane, where every worker clones its database + /// at once and a first connection can take longer than 3 s. async fn db() -> Db { let database_url = std::env::var("BUZZ_TEST_DATABASE_URL") .unwrap_or_else(|_| DbConfig::default().database_url); Db::new(&DbConfig { database_url, + min_connections: 0, + acquire_timeout_secs: 30, ..DbConfig::default() }) .await diff --git a/crates/buzz-agent/tests/fake_llm.rs b/crates/buzz-agent/tests/fake_llm.rs index 86c469f982..84dbf23c12 100644 --- a/crates/buzz-agent/tests/fake_llm.rs +++ b/crates/buzz-agent/tests/fake_llm.rs @@ -1521,17 +1521,33 @@ async fn steer_rejected_on_empty_prompt() { json!({"sessionId": sid, "expectedRunId": run_id, "prompt": []}), ) .await; - let mut saw_reject = false; + // The prompt runs in its own task while the steer is answered from the + // read loop, so the turn can finish before the steer is even read: wait + // for both responses in either order. + let (mut steer_reply, mut prompt_done) = (None, false); for _ in 0..40 { - let v = h.recv().await; - if v["id"] == json!(s_id) { - assert_eq!(v["error"]["code"], -32602, "empty prompt must be rejected"); - saw_reject = true; - } else if v["id"] == json!(p_id) { + if steer_reply.is_some() && prompt_done { break; } + let v = h.recv().await; + if v["id"] == json!(s_id) { + steer_reply = Some(v); + } else if v["id"] == json!(p_id) { + prompt_done = true; + } } - assert!(saw_reject, "empty steer prompt was not rejected"); + let steer_reply = steer_reply.expect("empty steer prompt got no response"); + assert_eq!( + steer_reply["error"]["code"], -32602, + "empty prompt must be rejected" + ); + // "no active run" and a run-id mismatch also answer -32602, and either can + // win if the turn ends first; the empty-prompt guard runs before both. + assert_eq!( + steer_reply["error"]["message"], "steer: prompt must not be empty", + "the empty-prompt guard must be what rejects the steer" + ); + assert!(prompt_done, "session/prompt did not finish"); h.shutdown().await; } diff --git a/crates/buzz-cli/src/client.rs b/crates/buzz-cli/src/client.rs index babf710b5a..9749c0ece1 100644 --- a/crates/buzz-cli/src/client.rs +++ b/crates/buzz-cli/src/client.rs @@ -3626,26 +3626,28 @@ mod desktop_throttle_tests { (BuzzClient::new(relay.into(), credentials).unwrap(), signed) } - /// A desktop allowing one sign-in signature per 300 ms against a relay - /// that drops unsigned sockets after 200 ms: the throttle is waited out - /// between connections, so only the live challenge is signed, with a - /// fresh assertion on the reconnect after the old one expired. + /// A desktop that throttles the first sign-in signature: the throttle is + /// waited out between connections, so only the live challenge is signed, + /// with a fresh assertion on the reconnect after the old one expired. + /// + /// The throttle is decided by call count, not by time since the test + /// started: on a loaded runner the desktop setup alone could outlast a + /// wall-clock throttle window, leaving nothing to wait out. The relay's + /// sign-in deadline is long for the same reason; the client drops the + /// throttled socket itself. #[tokio::test] async fn a_throttled_sign_in_reconnects_with_fresh_evidence() { use super::ws_deadline_tests::deadline_relay; let keys = nostr::Keys::generate(); - let (relay, conns, _, bearers) = - deadline_relay(std::time::Duration::from_millis(200)).await; - let last = std::sync::Mutex::new(std::time::Instant::now()); + let (relay, conns, _, bearers) = deadline_relay(std::time::Duration::from_secs(5)).await; + let signs = AtomicUsize::new(0); let (c, signed) = desktop(&relay, &keys, || dp::assertion(40), move |_| { - let mut last = last.lock().unwrap(); - if last.elapsed() < std::time::Duration::from_millis(300) { + if signs.fetch_add(1, Ordering::SeqCst) == 0 { crate::cached_assertion::test_clock::advance(60); return Some( serde_json::json!({"result": "", "error": "rate_limited", "retry_after": 30}), ); } - *last = std::time::Instant::now(); None }) .await;