Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -387,7 +387,20 @@ func (d *testDriver) syncEventCallback(sessionID string, syncMsg *types.SyncMess
// Ignore completions from previous rounds. Two checks:
// 1. Request ID must contain the current agent name
// 2. Thread ID must belong to the current round
if !strings.Contains(requestID, agentName) {
//
// Check 1 is a heuristic that only holds for the synthetic ids this
// harness mints itself (req-phaseN-<agent>). The production-queue phases
// (16/17) drive real Helix interactions, whose ids are ULIDs like
// int_01kyry6ejk... and contain no agent name — so the heuristic rejects
// LIVE completions for the current round and logs them as "wrong agent".
// That is worse than useless during triage: it asserts the opposite of
// what happened, and cost real time chasing a phantom routing bug when
// Phase 17 was actually hitting a cancel race.
//
// Helix-minted ids are round-safe anyway (each round gets fresh sessions
// and threads), so defer to the precise thread check below for them.
isHelixInteractionID := strings.HasPrefix(requestID, "int_")
if !isHelixInteractionID && !strings.Contains(requestID, agentName) {
d.mu.Unlock()
log.Printf("[%s] FILTERED completion (wrong agent): req=%s thread=%s",
agentName, requestID, truncate(acpThreadID, 12))
Expand Down
49 changes: 43 additions & 6 deletions crates/external_websocket_sync/e2e-test/run_e2e.sh
Original file line number Diff line number Diff line change
Expand Up @@ -44,7 +44,11 @@ cleanup() {

# Dump Zed errors/panics (full log available at ZED_LOG_FILE)
if [ -f "${ZED_LOG_FILE:-}" ]; then
ZED_ERRORS=$(grep -ciE "panic|error|fatal" "$ZED_LOG_FILE" 2>/dev/null || echo "0")
# NB: `grep -c` PRINTS the count and EXITS NON-ZERO when the count is 0, so
# `$(grep -c ... || echo 0)` yields the two-line string "0\n0" and every
# subsequent `[ "$X" -gt 0 ]` dies with "integer expression expected".
# Put the fallback on the assignment, not inside the substitution.
ZED_ERRORS=$(grep -ciE "panic|error|fatal" "$ZED_LOG_FILE" 2>/dev/null) || ZED_ERRORS=0
if [ "$ZED_ERRORS" -gt 0 ]; then
echo ""
echo "=================================================="
Expand All @@ -54,14 +58,34 @@ cleanup() {
echo " (full log: $ZED_LOG_FILE)"
fi
# ACP_SPAWN/ACP_DEDUP are at log::info level — surface them explicitly
ACP_LINES=$(grep -cE "ACP_SPAWN|ACP_DEDUP" "$ZED_LOG_FILE" 2>/dev/null || echo "0")
ACP_LINES=$(grep -cE "ACP_SPAWN|ACP_DEDUP" "$ZED_LOG_FILE" 2>/dev/null) || ACP_LINES=0
if [ "$ACP_LINES" -gt 0 ]; then
echo ""
echo "=================================================="
echo " ACP_SPAWN / ACP_DEDUP ($ACP_LINES lines)"
echo "=================================================="
grep -E "ACP_SPAWN|ACP_DEDUP" "$ZED_LOG_FILE" || true
fi

# Turn lifecycle: cancel / interrupt / silence-watchdog decisions.
#
# These are the events needed to tell the three failure shapes apart when
# a round fails, and reading them from the Helix side alone is impossible
# (Helix sees completions, not the ordering that produced them):
# - cancel landing on the wrong turn -> CANCEL_TASK vs THREAD_SERVICE order
# - a stale cancel correctly dropped -> "Stale cancel ignored"
# - agent accepted a prompt then died -> helix_silent_prompt_wedge
# Without this block the harness reported only "phase N timed out", which
# is not enough to attribute a failure.
LIFECYCLE_RE="CANCEL_TASK|Interrupt flag set|Stale cancel ignored|helix_silent_prompt_wedge|THREAD_SERVICE\] (Sending follow-up|Updated request_id|Sending to existing)"
LIFECYCLE_LINES=$(grep -cE "$LIFECYCLE_RE" "$ZED_LOG_FILE" 2>/dev/null) || LIFECYCLE_LINES=0
if [ "$LIFECYCLE_LINES" -gt 0 ]; then
echo ""
echo "=================================================="
echo " TURN LIFECYCLE / CANCEL ORDERING ($LIFECYCLE_LINES lines)"
echo "=================================================="
grep -E "$LIFECYCLE_RE" "$ZED_LOG_FILE" | tail -60 || true
fi
# Persist the full zed log into the mounted screenshots dir for offline inspection
if [ -d "$SCREENSHOT_DIR" ]; then
cp "$ZED_LOG_FILE" "$SCREENSHOT_DIR/zed-e2e.log" 2>/dev/null || true
Expand Down Expand Up @@ -199,10 +223,23 @@ if echo "$E2E_AGENTS" | grep -q "claude"; then
LOCAL_VERSION=$(node -e "console.log(require('/opt/claude-agent-acp/package.json').version)" 2>/dev/null || echo "unknown")
echo "[setup] Using LOCAL claude-agent-acp v$LOCAL_VERSION from /opt/claude-agent-acp"
else
# Log which version npx will install so we can correlate failures
# with claude-agent-acp upgrades. This is a quick check, not an install.
CLAUDE_ACP_VERSION=$(npm view @anthropic-ai/claude-agent-acp version 2>/dev/null || echo "unknown")
echo "[setup] Using npm-installed claude-agent-acp (auto-install, latest=$CLAUDE_ACP_VERSION)"
# Log which version npx will install so we can correlate failures with
# claude-agent-acp upgrades. This is a quick check, not an install.
#
# The scope matters and has been wrong before: Zed installs
# @agentclientprotocol/claude-agent-acp (see crates/agent_servers/), NOT
# @anthropic-ai/... . Querying the wrong scope silently yields "unknown",
# which quietly disables the one signal that distinguishes "we regressed"
# from "the agent package changed under us" when the claude round fails.
CLAUDE_ACP_PKG="@agentclientprotocol/claude-agent-acp"
CLAUDE_ACP_VERSION=$(npm view "$CLAUDE_ACP_PKG" version 2>/dev/null || echo "")
if [ -z "$CLAUDE_ACP_VERSION" ]; then
echo "[setup] WARNING: could not resolve a version for $CLAUDE_ACP_PKG."
echo "[setup] A claude-round failure will NOT be attributable to an agent-package change."
CLAUDE_ACP_VERSION="unknown"
fi
echo "[setup] Using npm-installed claude-agent-acp $CLAUDE_ACP_PKG (auto-install, latest=$CLAUDE_ACP_VERSION)"
echo "[setup] NOTE: this install is UNPINNED — the claude round is not reproducible across time."
fi
AGENT_SERVERS_JSON=$(cat << AGENTEOF
"agent_servers": {
Expand Down
39 changes: 32 additions & 7 deletions crates/external_websocket_sync/src/external_websocket_sync.rs
Original file line number Diff line number Diff line change
Expand Up @@ -87,10 +87,29 @@ static GLOBAL_UI_STATE_QUERY_CALLBACK: parking_lot::Mutex<Option<mpsc::Unbounded
static GLOBAL_CANCELLATION_CALLBACK: parking_lot::Mutex<Option<mpsc::UnboundedSender<CancellationRequest>>> =
parking_lot::Mutex::new(None);

/// Request to cancel a thread's running turn out-of-band.
#[derive(Clone, Debug)]
pub struct CancelThreadRequest {
pub acp_thread_id: String,
/// The turn this cancel is *intended* for, if the caller knows it.
///
/// Cancelling is asynchronous and races the sequential creation loop: by the
/// time the cancel task runs, the turn the caller meant to kill may already
/// have finished and a NEW turn may have started on the same thread. Firing
/// blind then cancels the wrong turn — the new interaction completes
/// immediately with no response, and its real completion is later discarded
/// as a stale request_id rebind.
///
/// When set, the cancel task only cancels if the thread's current request_id
/// still matches, so a stale cancel becomes a no-op instead of collateral
/// damage. `None` means "cancel whatever is running" (explicit user stop).
pub expected_request_id: Option<String>,
}

/// Static global for cancel-thread callback.
/// Receives an acp_thread_id and immediately cancels that thread's running turn,
/// Receives a [`CancelThreadRequest`] and cancels that thread's running turn,
/// bypassing the sequential callback_rx loop (which would be blocked awaiting the turn).
static GLOBAL_CANCEL_THREAD_CALLBACK: parking_lot::Mutex<Option<mpsc::UnboundedSender<String>>> =
static GLOBAL_CANCEL_THREAD_CALLBACK: parking_lot::Mutex<Option<mpsc::UnboundedSender<CancelThreadRequest>>> =
parking_lot::Mutex::new(None);

/// Pending UI state queries that arrived before AgentPanel was ready
Expand Down Expand Up @@ -552,13 +571,19 @@ mod protocol_test;
/// This bypasses the sequential callback_rx loop (which blocks waiting for turn
/// completion) by routing through a dedicated cancel GPUI task.
/// Called when Helix sends a chat_message with interrupt=true.
pub fn request_cancel_thread(acp_thread_id: String) -> Result<()> {
eprintln!("⚡ [CANCEL] request_cancel_thread() called for thread: {}", acp_thread_id);
log::info!("⚡ [CANCEL] request_cancel_thread() called for thread: {}", acp_thread_id);
pub fn request_cancel_thread(
acp_thread_id: String,
expected_request_id: Option<String>,
) -> Result<()> {
eprintln!("⚡ [CANCEL] request_cancel_thread() called for thread: {} (expecting turn {:?})",
acp_thread_id, expected_request_id);
log::info!("⚡ [CANCEL] request_cancel_thread() called for thread: {} (expecting turn {:?})",
acp_thread_id, expected_request_id);

let sender = GLOBAL_CANCEL_THREAD_CALLBACK.lock().clone();
if let Some(sender) = sender {
sender.send(acp_thread_id)
sender
.send(CancelThreadRequest { acp_thread_id, expected_request_id })
.map_err(|_| anyhow::anyhow!("Failed to send cancel request"))?;
Ok(())
} else {
Expand All @@ -571,7 +596,7 @@ pub fn request_cancel_thread(acp_thread_id: String) -> Result<()> {
}

/// Initialize the global cancel-thread callback (called from thread_service).
pub fn init_cancel_thread_callback(sender: mpsc::UnboundedSender<String>) {
pub fn init_cancel_thread_callback(sender: mpsc::UnboundedSender<CancelThreadRequest>) {
eprintln!("🔧 [CANCEL] init_cancel_thread_callback() called - registering global callback");
log::info!("🔧 [CANCEL] init_cancel_thread_callback() called - registering global callback");
*GLOBAL_CANCEL_THREAD_CALLBACK.lock() = Some(sender);
Expand Down
Loading
Loading