From 69df921856974a2d4db6d556e1cd46142861639a Mon Sep 17 00:00:00 2001 From: Huskies Agent Date: Thu, 16 Jul 2026 09:05:23 +0000 Subject: [PATCH] =?UTF-8?q?huskies:=20merge=201170=20bug=20Full=20tokio=20?= =?UTF-8?q?runtime=20stall=20after=20unblock=20=E2=86=92=20merge=20auto-as?= =?UTF-8?q?sign?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- server/src/agents/pool/auto_assign/merge.rs | 142 +++++++++++++++++--- 1 file changed, 122 insertions(+), 20 deletions(-) diff --git a/server/src/agents/pool/auto_assign/merge.rs b/server/src/agents/pool/auto_assign/merge.rs index 46e02493..b5335b57 100644 --- a/server/src/agents/pool/auto_assign/merge.rs +++ b/server/src/agents/pool/auto_assign/merge.rs @@ -65,27 +65,43 @@ impl AgentPool { // AC6: Detect empty-diff stories before starting the merge pipeline. // If the worktree has no commits on the feature branch, block the // story immediately via the state machine — no merge job needed. - if let Some(wt_path) = worktree::find_worktree_path(project_root, story_id) - && !crate::agents::gates::worktree_has_committed_work(&wt_path) - { - let empty_diff_reason = "Feature branch has no code changes — the coder agent \ - did not produce any commits."; - slog_warn!( - "[auto-assign] Story '{story_id}' in 4_merge/ has no commits \ - on feature branch. Blocking via state machine." - ); - if let Err(e) = - crate::agents::lifecycle::transition_to_blocked(story_id, empty_diff_reason) - { - slog_error!("[auto-assign] Failed to transition '{story_id}' to Blocked: {e}"); + // + // Bug 1170: worktree_has_committed_work shells out to `git log` + // synchronously. assign_merge_stage runs on the shared tokio + // runtime (it's invoked reactively on every CRDT transition, incl. + // unblock), so calling it inline here blocked a runtime worker + // thread for the duration of the git subprocess — with a story + // whose worktree/agent had crashed, that call could hang + // indefinitely and stall /health and the liveness heartbeat along + // with it. Run it on the blocking-thread pool instead. + if let Some(wt_path) = worktree::find_worktree_path(project_root, story_id) { + let has_commits = tokio::task::spawn_blocking(move || { + crate::agents::gates::worktree_has_committed_work(&wt_path) + }) + .await + .unwrap_or(false); + if !has_commits { + let empty_diff_reason = "Feature branch has no code changes — the coder agent \ + did not produce any commits."; + slog_warn!( + "[auto-assign] Story '{story_id}' in 4_merge/ has no commits \ + on feature branch. Blocking via state machine." + ); + if let Err(e) = + crate::agents::lifecycle::transition_to_blocked(story_id, empty_diff_reason) + { + slog_error!( + "[auto-assign] Failed to transition '{story_id}' to Blocked: {e}" + ); + } + let _ = self + .watcher_tx + .send(crate::io::watcher::WatcherEvent::StoryBlocked { + story_id: story_id.to_string(), + reason: empty_diff_reason.to_string(), + }); + continue; } - let _ = self - .watcher_tx - .send(crate::io::watcher::WatcherEvent::StoryBlocked { - story_id: story_id.to_string(), - reason: empty_diff_reason.to_string(), - }); - continue; } // Skip if a merge job is already running for this story (e.g. triggered @@ -111,3 +127,89 @@ impl AgentPool { } } } + +#[cfg(test)] +mod tests { + use super::super::super::AgentPool; + use crate::config::ProjectConfig; + use std::sync::Arc; + use std::sync::atomic::{AtomicU64, Ordering}; + + /// Bug 1170 regression: `assign_merge_stage` used to call + /// `worktree_has_committed_work` (which shells out to `git`) directly on + /// the async runtime. For a story with a crashed/unassignable agent + /// sitting in `4_merge/`, that synchronous subprocess call had no yield + /// point, so on a runtime with few worker threads it starved every other + /// task — including the liveness heartbeat and `/health` — for the whole + /// scan. After wrapping the call in `spawn_blocking`, the executor stays + /// free to interleave other work while the git subprocess runs + /// off-runtime. + /// + /// This reproduces the unblock → merge-auto-assign path: a story sits in + /// `4_merge/` with no active agent entry (the crashed/unassignable case) + /// and a worktree directory that isn't a real git repo, forcing every + /// `git` invocation in the scan to fail — but only after paying the + /// process fork/exec cost, which is what stalls a non-yielding runtime. + #[tokio::test(flavor = "multi_thread", worker_threads = 1)] + async fn assign_merge_stage_does_not_stall_liveness_heartbeat() { + crate::db::ensure_content_store(); + + let tmp = tempfile::tempdir().unwrap(); + let root = tmp.path().to_path_buf(); + std::fs::create_dir_all(root.join(".huskies")).unwrap(); + std::fs::write(root.join(".huskies/project.toml"), "").unwrap(); + + let worktrees_dir = root.join(".huskies/worktrees"); + std::fs::create_dir_all(&worktrees_dir).unwrap(); + + // Simulate several stories stuck in 4_merge/ with a crashed/unassignable + // agent: each has a worktree directory (so find_worktree_path succeeds + // and the git-shelling check runs) but is not a real git repo and has + // no active agent entry in the pool. + const STORY_COUNT: usize = 25; + for i in 0..STORY_COUNT { + let story_id = format!("11700_merge_{i:03}"); + std::fs::create_dir_all(worktrees_dir.join(&story_id)).unwrap(); + crate::db::write_item_with_content( + &story_id, + "4_merge", + "---\nname: Crashed Merge\n---\n", + crate::db::ItemMeta::named("Crashed Merge"), + ); + } + + let pool = AgentPool::new_test(3200); + let config = ProjectConfig::load(&root).unwrap_or_default(); + + // Stand in for the liveness heartbeat (tick_loop.rs's + // spawn_liveness_tick) and /health polling: a tight-interval task + // racing the merge scan on the single-worker-thread runtime. + let ticks = Arc::new(AtomicU64::new(0)); + let ticks_clone = Arc::clone(&ticks); + let heartbeat = tokio::spawn(async move { + loop { + tokio::time::sleep(std::time::Duration::from_millis(2)).await; + ticks_clone.fetch_add(1, Ordering::SeqCst); + } + }); + + let start = std::time::Instant::now(); + pool.assign_merge_stage(&root, &config).await; + let elapsed = start.elapsed(); + + heartbeat.abort(); + let observed_ticks = ticks.load(Ordering::SeqCst); + + // With a 2ms heartbeat cadence, an unstalled runtime should have + // fired roughly elapsed/2ms ticks. Require at least a quarter of that + // as a generous floor — a stalled runtime (pre-fix) produces ~0 ticks + // because the single worker thread never yields during the scan. + let expected_min_ticks = (elapsed.as_millis() / 2 / 4) as u64; + assert!( + observed_ticks >= expected_min_ticks, + "liveness heartbeat stalled during assign_merge_stage: {observed_ticks} tick(s) \ + over {elapsed:?} (expected at least ~{expected_min_ticks}); the merge scan likely \ + blocked the tokio runtime instead of yielding via spawn_blocking" + ); + } +}