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
This commit is contained in:
6 files changed
+305
-9
No files matched your search
@@ -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" <<EOF
|
||||
model: hangc:hang-model
|
||||
clients:
|
||||
- type: openai
|
||||
name: hangc
|
||||
auth: none
|
||||
api_key: 'unused'
|
||||
api_base: http://127.0.0.1:$PORT_J/v1
|
||||
models:
|
||||
- name: hang-model
|
||||
max_input_tokens: 100000
|
||||
supports_function_calling: true
|
||||
save: false
|
||||
memory: false
|
||||
stream: false
|
||||
EOF
|
||||
|
||||
# Agent-level hooks resolve without any global_hooks whitelisting, so the
|
||||
# probe agent carries its own markers for every terminal agent event.
|
||||
cat > "$CFG_J/agents/probe-int/config.yaml" <<EOF
|
||||
name: probe-int
|
||||
description: ctrl-c interruption probe agent
|
||||
version: 0.1.0
|
||||
instructions: |
|
||||
You are a probe agent. Reply briefly.
|
||||
hooks:
|
||||
agent.started:
|
||||
- name: mark
|
||||
command: "echo STARTED >> $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"
|
||||
@@ -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
|
||||
|
||||
@@ -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),
|
||||
|
||||
+54
-6
@@ -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")]
|
||||
|
||||
@@ -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();
|
||||
}
|
||||
|
||||
|
||||
+46
-1
@@ -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, Error>(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);
|
||||
|
||||
Reference in new issue
Block a user