From c73d5317a08021f539c59d898d597594b29e3f42 Mon Sep 17 00:00:00 2001 From: Alex Clarke Date: Wed, 16 Sep 2026 20:31:36 -0600 Subject: [PATCH] feat(TASK-049): harden hook dispatch against NUL env values and nested-supervisor latch misses - strip interior NUL bytes from hook env values in fire_resolved so agent-authored text (e.g. escalation questions) cannot suppress a hook via a failed spawn; raise the spawn-failure log to warn! - make Supervisor::has_active_tasks recurse into child supervisors, mirroring cancel_recursive, so a prompt ctrl-c that cancels only a grandchild still latches as an interruption - document the signal-first vs error-first classification asymmetry at top_level_agent_finished / SpawnResultHooks::fire and the deliberate REPL teardown cancel; pin ctrlc-with-no-error => agent.interrupted - probe Scenario J: pty-driven ctrl-c during a live headless --agent run fires exactly one agent.interrupted with no COYOTE_AGENT_ERROR --- scripts/usage-probe-hooks.sh | 154 ++++++++++++++++++++++++++++++++++ src/config/request_context.rs | 45 +++++++++- src/function/agents.rs | 5 +- src/hooks.rs | 60 +++++++++++-- src/repl/mod.rs | 3 + src/supervisor/mod.rs | 47 ++++++++++- 6 files changed, 305 insertions(+), 9 deletions(-) diff --git a/scripts/usage-probe-hooks.sh b/scripts/usage-probe-hooks.sh index 90326e1..2943153 100755 --- a/scripts/usage-probe-hooks.sh +++ b/scripts/usage-probe-hooks.sh @@ -29,6 +29,10 @@ # fresh named session fires exactly one session.started (and no # session.resumed); resuming a persisted session fires exactly one # session.resumed (and no session.started). +# J) pressing ctrl-c in a real terminal during a live headless --agent run +# fires exactly one agent.interrupted with NO COYOTE_AGENT_ERROR, and +# never agent.failed or agent.completed (needs python3 for the pty and +# the hanging LLM endpoint; skipped when python3 is unavailable). # # Not covered here (see src/function/mod.rs tests for tool.* + payload-file # coverage instead): a live tool.started firing requires a real LLM round @@ -495,5 +499,155 @@ wait_for "session.resumed log" scenario_i_resumed || fail "resuming a session must not fire session.started: $(cat "$SESS_LOG")" echo "PASS: fresh session fires session.started only; resume fires session.resumed only" +echo "== Scenario J: terminal ctrl-c during a live headless --agent run fires agent.interrupted ==" +if ! command -v python3 > /dev/null 2>&1; then + echo "SKIP: python3 not available; cannot allocate a pty or hanging LLM endpoint" >&2 +else + CFG_J="$WORKDIR/j" + mkdir -p "$CFG_J/agents/probe-int" + INT_LOG="$WORKDIR/j-int.log" + + # A local "LLM endpoint" that accepts connections and never answers keeps + # the agent run in flight (spinner active, its ctrl-c watcher polling) + # while the probe delivers ^C. It writes its port to $1 once listening and + # touches $2 on the first accepted connection, so the runner below can + # gate the ^C on the request being demonstrably in flight. + python3 - "$WORKDIR/j-port" "$WORKDIR/j-conn" <<'PY' & +import socket, sys +s = socket.socket() +s.bind(("127.0.0.1", 0)) +s.listen(8) +open(sys.argv[1], "w").write(str(s.getsockname()[1])) +conns = [] +while True: + c, _ = s.accept() + if not conns: + open(sys.argv[2], "w").write("1") + conns.append(c) +PY + SRV_J=$! + trap 'kill "$SRV_J" 2>/dev/null || true; rm -rf "$WORKDIR"' EXIT + wait_for "hang-server port" test -s "$WORKDIR/j-port" + PORT_J="$(cat "$WORKDIR/j-port")" + + cat > "$CFG_J/config.yaml" < "$CFG_J/agents/probe-int/config.yaml" <> $INT_LOG" + agent.completed: + - name: mark + command: "echo COMPLETED >> $INT_LOG" + agent.failed: + - name: mark + command: "echo \"FAILED err=\${COYOTE_AGENT_ERROR:-unset}\" >> $INT_LOG" + agent.interrupted: + - name: mark + command: "echo \"INTERRUPTED err=\${COYOTE_AGENT_ERROR:-unset}\" >> $INT_LOG" +EOF + + # Spawn coyote on a real pty (the spinner's ctrl-c watcher only runs on a + # terminal), wait until the agent.started marker AND the first accepted + # LLM connection prove the run is in flight, then send a literal ^C + # through the pty line discipline — exactly what a terminal user does. + cat > "$WORKDIR/j-pty.py" <<'PY' +import os, pty, sys, time + +int_log, conn_marker = sys.argv[1], sys.argv[2] +argv = sys.argv[3:] + +pid, master = pty.fork() +if pid == 0: + os.execvp(argv[0], argv) + +os.set_blocking(master, False) + +def drain(): + try: + while os.read(master, 4096): + pass + except OSError: + pass + +def marker_seen(): + try: + with open(int_log) as f: + return "STARTED" in f.read() + except FileNotFoundError: + return False + +deadline = time.time() + 15 +while time.time() < deadline: + drain() + if marker_seen() and os.path.exists(conn_marker): + break + time.sleep(0.1) +else: + print("TIMEOUT: agent.started marker / LLM connection never appeared", flush=True) + os.kill(pid, 9) + os.waitpid(pid, 0) + sys.exit(3) + +os.write(master, b"\x03") # ^C via the pty line discipline + +deadline = time.time() + 15 +while time.time() < deadline: + drain() + got, status = os.waitpid(pid, os.WNOHANG) + if got == pid: + if os.WIFSIGNALED(status): + print(f"FATAL: coyote died on signal {os.WTERMSIG(status)} — no ctrl-c handler was installed", flush=True) + sys.exit(4) + sys.exit(0) + time.sleep(0.1) + +print("TIMEOUT: coyote did not exit within 15s of ^C", flush=True) +os.kill(pid, 9) +os.waitpid(pid, 0) +sys.exit(3) +PY + + COYOTE_CONFIG_DIR="$CFG_J" python3 "$WORKDIR/j-pty.py" "$INT_LOG" "$WORKDIR/j-conn" \ + "$BIN" --agent probe-int --no-stream "say exactly: hi" \ + || fail "pty ctrl-c run did not exit cleanly (see message above)" + + scenario_j_interrupted() { grep -qs '^INTERRUPTED err=unset$' "$INT_LOG"; } + wait_for "agent.interrupted log" scenario_j_interrupted + [ "$(grep -c '^STARTED$' "$INT_LOG" 2>/dev/null || echo 0)" = "1" ] \ + || fail "expected exactly one agent.started, got: $(cat "$INT_LOG")" + [ "$(grep -c '^INTERRUPTED' "$INT_LOG" 2>/dev/null || echo 0)" = "1" ] \ + || fail "expected exactly one agent.interrupted, got: $(cat "$INT_LOG")" + grep -q '^FAILED' "$INT_LOG" \ + && fail "ctrl-c must fire agent.interrupted, never agent.failed: $(cat "$INT_LOG")" + grep -q '^COMPLETED' "$INT_LOG" \ + && fail "an interrupted run must not fire agent.completed: $(cat "$INT_LOG")" + kill "$SRV_J" 2>/dev/null || true + echo "PASS: terminal ctrl-c fires exactly one agent.interrupted with no COYOTE_AGENT_ERROR; never failed/completed" +fi + echo echo "ALL SCENARIOS PASSED" diff --git a/src/config/request_context.rs b/src/config/request_context.rs index b7566e2..7daf797 100644 --- a/src/config/request_context.rs +++ b/src/config/request_context.rs @@ -4972,7 +4972,14 @@ impl RequestContext { }; // The abort signal, never the error text, decides interrupted: a - // ctrl-c'd run is not a failure, so no error env rides along. + // ctrl-c'd run is not a failure, so no error env rides along. The + // gate is deliberately signal-first -- a latched ctrl-c means + // interrupted even with no error in hand -- unlike + // SpawnResultHooks::fire, which is error-first: a child that finished + // cleanly stays agent.completed under a latched signal because its + // output is collectible. Blind spot: a mid-stream ctrl-d aborts live + // work via poll_abort_signal yet still classifies as agent.completed, + // because ctrl-d always means a deliberate exit (accepted). if abort_signal.is_some_and(|signal| signal.aborted_ctrlc()) { hooks::fire( HookEvent::AgentInterrupted, @@ -8619,6 +8626,42 @@ mod tests { })); } + #[test] + #[serial] + fn top_level_agent_ctrlc_without_error_fires_agent_interrupted() { + let _guard = TestConfigDirGuard::new(); + let _sink = test_sink::install(); + let marker = "agent-top-int-noerr-v4d"; + let agent_name = unique_name("hook_agent"); + seed_agent_with_hooks(&agent_name, marker); + + let mut ctx = create_test_ctx(); + let app = ctx.app.config.clone(); + let abort = utils::create_abort_signal(); + run_async(ctx.use_agent(&app, &agent_name, None, abort.clone())).unwrap(); + + ctx.top_level_agent_started(); + abort.set_ctrlc(); + // Signal-first: a latched ctrl-c means interrupted even when the run + // surfaced no error at all. + ctx.top_level_agent_finished(None, Some(&abort)); + + let captures = marker_captures(marker); + assert_eq!( + captures + .iter() + .filter(|capture| capture.hook_name == format!("{marker}-agent.interrupted")) + .count(), + 1 + ); + assert!( + captures + .iter() + .all(|capture| capture.hook_name != format!("{marker}-agent.completed")), + "a ctrl-c'd run must not report completion" + ); + } + /// The REPL's advertised exit path -- ctrl-c at an idle prompt (which /// prints "To exit, press Ctrl+D"), then ctrl-d -- is a deliberate exit: /// with no active tasks to cancel the prompt latch stays clear, so diff --git a/src/function/agents.rs b/src/function/agents.rs index 4ff0bc6..ac19b3a 100644 --- a/src/function/agents.rs +++ b/src/function/agents.rs @@ -1029,7 +1029,10 @@ impl SpawnResultHooks { /// Fires `agent.completed`, or — for a failed child — `agent.interrupted` /// when its abort signal was ctrl-c'd (REPL ctrl-c or `agent__cancel`), /// else `agent.failed`. The signal, never the error text, decides: - /// cancellation is not a failure, so no error env rides along. + /// cancellation is not a failure, so no error env rides along. Unlike the + /// signal-first `top_level_agent_finished` gate, completion wins over a + /// latched ctrl-c at this seam — a finished child's output is collectible, + /// so the asymmetry is intentional. fn fire(self, error: Option<&str>, child_abort: &AbortSignal) { let mut extras = vec![ ("COYOTE_AGENT_ID", self.agent_id), diff --git a/src/hooks.rs b/src/hooks.rs index 8e3fe4b..ea47f66 100644 --- a/src/hooks.rs +++ b/src/hooks.rs @@ -348,6 +348,12 @@ pub fn fire_resolved( let envs: Vec<(String, String)> = envs .into_iter() .map(|(key, mut value)| { + // Values like escalation questions carry agent-authored text; + // an interior NUL makes `Command::spawn` fail on Unix, which + // would let a child suppress its own hooks. Strip them. + if value.contains('\0') { + value.retain(|c| c != '\0'); + } // `end` is a char boundary by construction, so `truncate` cannot panic. let end = truncate_env_value(&value).len(); value.truncate(end); @@ -629,7 +635,7 @@ async fn run_hook( let _ = child.wait().await; } Err(err) => { - debug!( + warn!( "Failed to spawn hook '{}' in '{}': {err}", hook.full_name, hook.cwd.display() @@ -1665,6 +1671,42 @@ mod tests { assert_eq!(capture.envs.get("COYOTE_BIG_EXTRA").unwrap().len(), 2048); } + #[test] + #[serial] + fn fire_resolved_strips_nul_bytes_from_env_values() { + let _guard = test_sink::install(); + let hook = ResolvedHook { + name: "nul-strip-probe-k4v".to_string(), + full_name: "escalation.raised.nul-strip-probe-k4v".to_string(), + command: "true".to_string(), + cwd: env::temp_dir(), + }; + + fire_resolved( + HookEvent::EscalationRaised, + vec![hook], + Vec::new(), + &[( + "COYOTE_ESCALATION_QUESTION", + "before\u{0000}after".to_string(), + )], + None, + ); + + let captures = test_sink::drain(); + let capture = captures + .iter() + .find(|capture| capture.hook_name == "nul-strip-probe-k4v") + .expect("a NUL in an env value must not suppress the hook"); + assert_eq!( + capture + .envs + .get("COYOTE_ESCALATION_QUESTION") + .map(String::as_str), + Some("beforeafter") + ); + } + #[test] #[serial] fn sink_recovers_after_capture_buffer_poisoning() { @@ -2020,7 +2062,7 @@ mod tests { // does the empty directory below demonstrate the orphan unlink // rather than a payload file that never existed. wait_for("spawn failure log", || { - crate::testing::debug_snapshot().iter().any(|message| { + crate::testing::warn_snapshot().iter().any(|message| { message.contains("Failed to spawn hook 'tool.started.spawnfail-marker-c9d'") }) }) @@ -2075,7 +2117,7 @@ mod tests { #[tokio::test(flavor = "multi_thread")] #[serial] - async fn error_paths_log_debug_only() { + async fn empty_command_logs_debug_and_spawn_failure_logs_warn() { crate::testing::install_log_collector(); let empty_cwd = env::temp_dir(); let hooks = vec![ @@ -2103,12 +2145,18 @@ mod tests { && message.contains("empty command") && message.contains(empty_cwd_display.as_str()) })); - assert!(debugs.iter().any(|message| { + // A failed spawn silently suppresses the hook, so it must be + // loud enough to notice; a skipped empty command stays debug. + let warns = crate::testing::warn_snapshot(); + assert!(warns.iter().any(|message| { message.contains("Failed to spawn hook 'turn.failed.badcwd-marker-f5b'") && message.contains("/nonexistent/coyote-badcwd-marker-f5b") })); - let warns = crate::testing::warn_snapshot(); - assert!(warns.iter().all(|message| !message.contains("marker-f5b"))); + assert!( + warns + .iter() + .all(|message| !message.contains("empty-marker-f5b")) + ); } #[tokio::test(flavor = "multi_thread")] diff --git a/src/repl/mod.rs b/src/repl/mod.rs index 69a0ec3..218962d 100644 --- a/src/repl/mod.rs +++ b/src/repl/mod.rs @@ -527,6 +527,9 @@ Type ".help" for additional help. } if let Some(supervisor) = self.ctx.read().supervisor.clone() { + // Leaving the loop is a deliberate exit, never an interruption: + // cancelling straggler children here does not latch the abort + // signal, so teardown still classifies as agent.completed. supervisor.read().cancel_recursive(); } diff --git a/src/supervisor/mod.rs b/src/supervisor/mod.rs index f80eb4e..7028637 100644 --- a/src/supervisor/mod.rs +++ b/src/supervisor/mod.rs @@ -192,8 +192,18 @@ impl Supervisor { /// True when any registered agent or job is still running -- i.e. a /// cancellation right now would actually interrupt in-flight work. + /// Mirrors `cancel_recursive`'s traversal: work buried in a nested child + /// supervisor still counts, so a prompt ctrl-c that cancels only a + /// grandchild latches like any other interruption. pub fn has_active_tasks(&self) -> bool { - self.effective_active_count() > 0 || self.active_job_count() > 0 + self.effective_active_count() > 0 + || self.active_job_count() > 0 + || self.agents().any(|agent| { + agent + .child_supervisor + .as_ref() + .is_some_and(|child_sup| child_sup.read().has_active_tasks()) + }) } pub fn max_concurrent(&self) -> usize { @@ -499,6 +509,41 @@ mod tests { assert!(sup.has_active_tasks()); } + #[test] + fn has_active_tasks_true_with_only_grandchild_activity() { + // Keep the runtime alive so the grandchild task is never polled and + // counts as running. + let rt = Builder::new_current_thread().enable_all().build().unwrap(); + let join_handle = rt.spawn(async { + Ok::(AgentResult { + id: "done".into(), + agent_name: "test".into(), + output: "result".into(), + exit_status: AgentExitStatus::Completed, + }) + }); + let grandchild = AgentHandle { + id: "g1".to_string(), + agent_name: "worker".to_string(), + depth: 2, + inbox: Arc::new(Inbox::new()), + abort_signal: create_abort_signal(), + join_handle, + child_supervisor: None, + }; + let mut child_sup = Supervisor::new(4, 3); + child_sup.register(grandchild).unwrap(); + + // make_handle's direct task is already finished, so the only live + // work sits one supervisor level down. + let mut parent_handle = make_handle("a1", "explore", 1); + parent_handle.child_supervisor = Some(Arc::new(RwLock::new(child_sup))); + let mut sup = Supervisor::new(4, 3); + sup.register(parent_handle).unwrap(); + + assert!(sup.has_active_tasks()); + } + #[test] fn supervisor_register_rejects_exceeding_depth() { let mut sup = Supervisor::new(4, 2);