From 952657efb49302a31d5b2b107a493f6fe56b58f5 Mon Sep 17 00:00:00 2001 From: Godopu Date: Sun, 13 Sep 2026 01:53:57 +0900 Subject: [PATCH] fix(issue-9,14): bound the R1 grace by the wall clock and keep other ls failures unknown Round-2 review of d5a191c (planner-reviewer-claude-01, planner-reviewer-codex-01). - delegate wrapper: the R1 idle grace and the broker_unavailable re-check counted only their sleeps against TIMEOUT, so python/herdr probe time plus fresh disk heartbeats let a job run far past --timeout (55 s for a 20 s budget in the new test). Both loops now end at START_TIME + TIMEOUT read off the clock on every pass; heartbeats extend only the idle window, and the herdr probe is cut off at the deadline (_within_deadline) - document the window policy d5a191c actually implements: an agent with no evidence is closed ~2 x IDLE_TIMEOUT after its last wire event (Issue #6 promised IDLE_TIMEOUT + 5 s) and heartbeats may be ~2 x IDLE_TIMEOUT apart; correct the claim that publish_event records a heartbeat on disk before the wire publish - it records right after the publish attempt - shim ls: every failed `agent list` other than a structured server_not_running now exits nonzero with a "state unknown" diagnostic instead of reaching the list parser, where an error document on stdout read as an empty list and let drift A terminate live rows - tests: stdout variants for down and unrelated errors, reconcile keeping herdr_confirmed False on an unrelated failure, and a wall-clock upper bound under continuous heartbeats and slow probes; the three new checks fail on d5a191c - VERSIONS.md v4.4.2: items 3 and 6 and the test count (19) Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01HCGpJXhSZasJLU38ksDghe --- .agents/skills/lib.sh | 11 +- .../multi-agent-mux-delegate-job | 97 +++++++++------ VERSIONS.md | 6 +- tests/test_issue14_delivery_ack.py | 74 ++++++++++++ tests/test_issue9_server_env.py | 110 ++++++++++++------ 5 files changed, 221 insertions(+), 77 deletions(-) diff --git a/.agents/skills/lib.sh b/.agents/skills/lib.sh index 25d5bf7..e189b32 100644 --- a/.agents/skills/lib.sh +++ b/.agents/skills/lib.sh @@ -1249,7 +1249,9 @@ except Exception: # error.code == "server_not_running" means "down". A successful list can # legitimately contain that text (an agent named server_not_running-codex), # and reading it as "down" made reconcile terminate every live row on that - # server. Any other failure falls through to the unknown path below. + # server. Any other failed call is "unknown": it exits nonzero below + # without its output ever reaching the list parser, so an error document on + # stdout cannot pass for an empty list either. _ls_err=$(mktemp 2>/dev/null || echo "/tmp/mam_ls_err_$$") _ls_rc=0 _ls_raw="$(_real_herdr agent list 2>"$_ls_err")" || _ls_rc=$? @@ -1281,6 +1283,13 @@ print(down) echo "no server running (herdr session ${_sess:-default})" >&2 exit 1 fi + if [ "$_ls_rc" -ne 0 ]; then + # Unknown, never empty: keep the nonzero status and word the diagnostic + # so it matches none of reconcile.sh's empty-server phrases ("no server + # running", "no sessions", "failed to connect"). + echo "herdr agent list returned rc=$_ls_rc (herdr session ${_sess:-default}); state unknown" >&2 + exit 1 + fi printf '%s\n' "$_ls_raw" | \ MAM_LS_FORMAT="$format" MAM_REAL_HERDR="$REAL_HERDR" MAM_LS_SESSION="$_sess" \ TZ=UTC LC_ALL=C python3 -c ' diff --git a/.agents/skills/multi-agent-mux-delegate-job/multi-agent-mux-delegate-job b/.agents/skills/multi-agent-mux-delegate-job/multi-agent-mux-delegate-job index 4b923bd..0abb104 100755 --- a/.agents/skills/multi-agent-mux-delegate-job/multi-agent-mux-delegate-job +++ b/.agents/skills/multi-agent-mux-delegate-job/multi-agent-mux-delegate-job @@ -599,12 +599,35 @@ _agent_still_working() { _pane_tail "$sess" 8 2>/dev/null | grep -Fq "esc to interrupt" } +# _within_deadline +# Run a probe that can block (a herdr RPC, a pane capture) without letting it +# outlive a wall-clock deadline: once the clock reaches the probe +# and its children are killed and the result is rc 124, i.e. "no evidence". +_within_deadline() { + local deadline="$1" pid + shift + "$@" & + pid=$! + while kill -0 "$pid" 2>/dev/null; do + if [ "$(date +%s)" -ge "$deadline" ]; then + pkill -P "$pid" 2>/dev/null || true + kill "$pid" 2>/dev/null || true + wait "$pid" 2>/dev/null || true + return 124 + fi + sleep 0.1 + done + wait "$pid" +} + # ISSUE-14: agent-agnostic liveness. publish_event appends every event to the -# job's on-disk events.log before the wire publish, so a `progress` heartbeat -# that the subscriber never saw (it had already idled out, or the broker -# dropped it) is still visible here. An agent running its tests in a -# background shell looks idle to herdr and shows no busy token, yet keeps -# heartbeating - this is the only evidence that covers that case. +# job's on-disk events.log right after its wire publish attempt, whether that +# publish succeeded or not, so a `progress` heartbeat the subscriber never saw +# (it had already idled out, or the broker dropped it) is still visible here - +# late by at most its publish retries while the broker is failing. An agent +# running its tests in a background shell looks idle to herdr and shows no +# busy token, yet keeps heartbeating - this is the only evidence that covers +# that case. _recent_disk_heartbeat() { local job_id="$1" window="$2" f="$REGISTRY_DIR/$job_id.events.log" [ -f "$f" ] || return 1 @@ -672,19 +695,18 @@ finalize_unfinished() { else FINAL_JOB_STATUS="$job_status" fi - # broker_unavailable: re-observe disk for remaining deadline at 3s intervals + # broker_unavailable: re-observe the disk at 3 s intervals until this + # dispatch's wall-clock deadline (START_TIME + TIMEOUT). The deadline is read + # off the clock on every pass; summing the sleeps alone ignores the time the + # disk probes themselves take and overruns TIMEOUT. if [ "$job_status" = "broker_unavailable" ]; then - local now elapsed remaining - now=$(date +%s) - elapsed=$(( now - ${START_TIME:-now} )) - remaining=$(( TIMEOUT - elapsed )) - [ $remaining -lt 0 ] && remaining=0 - while [ $remaining -gt 0 ]; do - local wait_interval=3 - [ $remaining -lt $wait_interval ] && wait_interval=$remaining - sleep "$wait_interval" - remaining=$(( remaining - wait_interval )) - local disk_st + local deadline left disk_st + deadline=$(( ${START_TIME:-$(date +%s)} + TIMEOUT )) + while :; do + left=$(( deadline - $(date +%s) )) + [ "$left" -le 0 ] && break + [ "$left" -gt 3 ] && left=3 + sleep "$left" disk_st="$(_disk_status "$job_id")" if [ "$disk_st" = "completed" ] || [ "$disk_st" = "error" ] || [ "$disk_st" = "cancelled" ]; then job_status="$disk_st" @@ -703,21 +725,23 @@ finalize_unfinished() { target_agent=$(_sanitize_herdr_agent_name "$sess") # ISSUE-14: the subscriber's idle clock only counts events it received over - # the wire. Keep re-observing the disk while ANY liveness evidence is at - # most IDLE_TIMEOUT old - herdr `working`, the pane busy token, or a fresh - # heartbeat in events.log (see _recent_disk_heartbeat). Each sighting opens - # a new idle window; an agent that leaves no evidence for a whole window is - # closed, still inside the wall clock. Before this, one heartbeat gap - # longer than the idle timeout closed a live review as deadline_timeout - # and its later `completed` was refused. - local now elapsed remaining evidence_until - now=$(date +%s) - elapsed=$(( now - ${START_TIME:-now} )) - remaining=$(( TIMEOUT - elapsed )) - [ $remaining -lt 0 ] && remaining=0 - evidence_until=$(( now + IDLE_TIMEOUT )) - while [ $remaining -gt 0 ]; do - local disk_st + # the wire. Keep re-observing the disk while liveness evidence keeps + # turning up - herdr `working`, the pane busy token, or a heartbeat in + # events.log at most IDLE_TIMEOUT old (see _recent_disk_heartbeat). + # Window policy: entering this grace opens one IDLE_TIMEOUT window and + # every sighting re-opens it from the time of that poll. An agent that + # leaves no evidence at all is therefore closed about 2 x IDLE_TIMEOUT + # after its last wire event (the subscriber's idle wait plus this window; + # it was IDLE_TIMEOUT before disk heartbeats counted), and heartbeats may + # be up to about 2 x IDLE_TIMEOUT apart, since one still counts until it + # is IDLE_TIMEOUT old. Evidence only ever extends the idle window, never + # this dispatch's wall clock: the loop ends at START_TIME + TIMEOUT read + # off the clock on every pass, and the herdr probe is cut off at that + # deadline too (_within_deadline). + local deadline evidence_until left disk_st + deadline=$(( ${START_TIME:-$(date +%s)} + TIMEOUT )) + evidence_until=$(( $(date +%s) + IDLE_TIMEOUT )) + while [ "$(date +%s)" -lt "$deadline" ]; do disk_st="$(_disk_status "$job_id")" if [ "$disk_st" = "completed" ] || [ "$disk_st" = "error" ] || [ "$disk_st" = "cancelled" ]; then job_status="$disk_st" @@ -725,16 +749,15 @@ finalize_unfinished() { [ "$disk_st" = "completed" ] && return 0 break fi - if { [ "$sess" != "human" ] && [ -n "$sess" ] && _agent_still_working "$sess" "$target_agent"; } \ + if { [ "$sess" != "human" ] && [ -n "$sess" ] && _within_deadline "$deadline" _agent_still_working "$sess" "$target_agent"; } \ || _recent_disk_heartbeat "$job_id" "$IDLE_TIMEOUT"; then evidence_until=$(( $(date +%s) + IDLE_TIMEOUT )) elif [ "$(date +%s)" -ge "$evidence_until" ]; then break fi - local wait_interval=1 - [ $remaining -lt $wait_interval ] && wait_interval=$remaining - sleep "$wait_interval" - remaining=$(( remaining - wait_interval )) + left=$(( deadline - $(date +%s) )) + [ "$left" -le 0 ] && break + sleep 1 done fi diff --git a/VERSIONS.md b/VERSIONS.md index 1bd4fc2..28feb8c 100644 --- a/VERSIONS.md +++ b/VERSIONS.md @@ -44,14 +44,14 @@ #### ๐ŸŒŸ ์ฃผ์š” ๊ฐœ์„  ์‚ฌํ•ญ 1. **herdr ์„œ๋ฒ„ ๊ธฐ๋™ env ๋งˆ์ปค denylist (Issue #9, `lib.sh` ์‰ผ)**: ์‰ผ์ด `herdr --session server` ๋ฅผ ๋ถ€ํŠธ์ŠคํŠธ๋žฉํ•  ๋•Œ ์„ธ์…˜ ์‹๋ณ„ ๋งˆ์ปค๋งŒ ์ œ๊ฑฐํ•œ ํ™˜๊ฒฝ์„ ๋„˜๊ธด๋‹ค โ€” `CLAUDECODE`, `CLAUDE_CODE_CHILD_SESSION`, `CLAUDE_CODE_SESSION_ID`, `CLAUDE_CODE_SESSION_ATTENDED`, `CLAUDE_CODE_ENTRYPOINT`, `CLAUDE_PID`, `CLAUDE_CODE_MESSAGING_TOKEN`, `CLAUDE_CODE_MESSAGING_SOCKET`, `CLAUDE_CODE_BRIDGE_SESSION_ID`, `ANTIGRAVITY_CONVERSATION_ID`, `HERMES_SESSION_ID`, `GROK_SESSION_ID`, `OPENCODE_SESSION_ID`. `CLAUDE_PROJECT_DIR`ยท`CLAUDE_CONFIG_DIR` ๋“ฑ ์‚ฌ์šฉ์ž ์„ค์ •์€ ๊ทธ๋Œ€๋กœ ์ƒ์†๋œ๋‹ค. ์ƒ์†๋œ `CLAUDE_CODE_CHILD_SESSION` ๋•Œ๋ฌธ์— ์„œ๋ธŒ์—์ด์ „ํŠธ claude ์˜ transcript ์ €์žฅ์ด ๊บผ์ ธ resume ์ด ๋ถˆ๊ฐ€๋Šฅํ•˜๋˜ ์ฆ์ƒ์„ ํ•ด์†Œ. 2. **์กฐํšŒ ๊ฒฝ๋กœ ์ž๋™ ๊ธฐ๋™ ๊ธˆ์ง€ `MAM_NO_AUTOSTART=1` (Issue #9)**: ์ด ๊ฐ’์ด ์„ค์ •๋˜๋ฉด ์‰ผ์€ ์„œ๋ฒ„๋ฅผ ๋„์šฐ์ง€ ์•Š๊ณ  ํ˜ธ์ถœ๋งŒ ์ „๋‹ฌํ•œ๋‹ค. `status.sh`ยท`reconcile.sh` ๊ฐ€ ์ด๋ฅผ export ํ•˜๋ฏ€๋กœ read-only `multi-agent-mux-status` ์กฐํšŒ๊ฐ€ ๋” ์ด์ƒ ์„œ๋ฒ„ ๋ฐ๋ชฌ์„ ๊ธฐ๋™ํ•˜์ง€ ์•Š๋Š”๋‹ค. -3. **์‰ผ `ls` ์˜ "no server running" ๋ฒˆ์—ญ (Issue #9)**: ์„œ๋ฒ„๊ฐ€ ๋‚ด๋ ค๊ฐ€ ์žˆ์œผ๋ฉด ์‰ผ์˜ `ls` ๊ฐ€ `no server running (herdr session )` ์œผ๋กœ ๋ณด๊ณ ํ•˜๊ณ , `reconcile.sh` ๋Š” ์ด๋ฅผ ๋นˆ ์„œ๋ฒ„๋กœ ํŒ์ •ํ•ด `herdr_confirmed` ๋ฅผ ์œ ์ง€ํ•œ๋‹ค(ํŒŒ์‹ฑ ์‹คํŒจ๋กœ ๋ชจ๋“  ์„œ๋ฒ„์˜ drift ๊ฐ์ง€๊ฐ€ ๋ฉˆ์ถ”๋Š” ํšŒ๊ท€ ๋ฐฉ์ง€). ๋ฒˆ์—ญ์€ `agent list` ๊ฐ€ **์‹คํŒจ**ํ•˜๊ณ  ๊ทธ ์˜ค๋ฅ˜ ๋ด‰ํˆฌ์˜ `error.code` ๊ฐ€ ์ •ํ™•ํžˆ `server_not_running` ์ผ ๋•Œ๋งŒ ์ ์šฉํ•œ๋‹ค. ์„ฑ๊ณตํ•œ ๋ชฉ๋ก์— ๊ฐ™์€ ๋ฌธ์ž์—ด์ด ๋“ค์–ด ์žˆ๊ฑฐ๋‚˜(์˜ˆ: ์—์ด์ „ํŠธ ์ด๋ฆ„ `server_not_running-codex`) ๋‹ค๋ฅธ ์‹คํŒจ์ธ ๊ฒฝ์šฐ๋Š” ๋ฒˆ์—ญํ•˜์ง€ ์•Š์œผ๋ฏ€๋กœ, ์‚ด์•„ ์žˆ๋Š” ์„œ๋ฒ„๊ฐ€ ๋นˆ ์„œ๋ฒ„๋กœ ์˜คํŒ๋˜์–ด drift A ๋กœ ์ „ ์„ธ์…˜์ด ์ข…๋ฃŒ ์ฒ˜๋ฆฌ๋˜์ง€ ์•Š๊ณ  ๊ทธ ๋ฐ–์˜ ์‹คํŒจ๋Š” ์ข…์ „๋Œ€๋กœ unknown(`herdr_confirmed=False`)์œผ๋กœ ๋‚จ๋Š”๋‹ค. +3. **์‰ผ `ls` ์˜ "no server running" ๋ฒˆ์—ญ (Issue #9)**: ์„œ๋ฒ„๊ฐ€ ๋‚ด๋ ค๊ฐ€ ์žˆ์œผ๋ฉด ์‰ผ์˜ `ls` ๊ฐ€ `no server running (herdr session )` ์œผ๋กœ ๋ณด๊ณ ํ•˜๊ณ , `reconcile.sh` ๋Š” ์ด๋ฅผ ๋นˆ ์„œ๋ฒ„๋กœ ํŒ์ •ํ•ด `herdr_confirmed` ๋ฅผ ์œ ์ง€ํ•œ๋‹ค(ํŒŒ์‹ฑ ์‹คํŒจ๋กœ ๋ชจ๋“  ์„œ๋ฒ„์˜ drift ๊ฐ์ง€๊ฐ€ ๋ฉˆ์ถ”๋Š” ํšŒ๊ท€ ๋ฐฉ์ง€). ๋ฒˆ์—ญ์€ `agent list` ๊ฐ€ **์‹คํŒจ**ํ•˜๊ณ  ๊ทธ ์˜ค๋ฅ˜ ๋ด‰ํˆฌ(stderrยทstdout ์–ด๋А ์ชฝ์ด๋“ )์˜ `error.code` ๊ฐ€ ์ •ํ™•ํžˆ `server_not_running` ์ผ ๋•Œ๋งŒ ์ ์šฉํ•œ๋‹ค. ์„ฑ๊ณตํ•œ ๋ชฉ๋ก์— ๊ฐ™์€ ๋ฌธ์ž์—ด์ด ๋“ค์–ด ์žˆ์œผ๋ฉด(์˜ˆ: ์—์ด์ „ํŠธ ์ด๋ฆ„ `server_not_running-codex`) ๋ฒˆ์—ญํ•˜์ง€ ์•Š์œผ๋ฏ€๋กœ ์‚ด์•„ ์žˆ๋Š” ์„œ๋ฒ„๊ฐ€ ๋นˆ ์„œ๋ฒ„๋กœ ์˜คํŒ๋˜์–ด drift A ๋กœ ์ „ ์„ธ์…˜์ด ์ข…๋ฃŒ ์ฒ˜๋ฆฌ๋˜์ง€ ์•Š๋Š”๋‹ค. ๊ทธ ๋ฐ–์˜ ์‹คํŒจ๋Š” ์ถœ๋ ฅ์ด ๋ชฉ๋ก ํŒŒ์„œ์— ๋‹ฟ๊ธฐ ์ „์— ๋น„-0 ์œผ๋กœ ๋๋‚˜(`โ€ฆ state unknown`, reconcile ์˜ ๋นˆ ์„œ๋ฒ„ ๋ฌธ๊ตฌ์™€ ๊ฒน์น˜์ง€ ์•Š์Œ) unknown(`herdr_confirmed=False`)์œผ๋กœ ๋‚จ๋Š”๋‹ค โ€” stdout ์œผ๋กœ ์˜จ ์˜ค๋ฅ˜ ๋ฌธ์„œ๋„ ๋” ์ด์ƒ ๋นˆ ๋ชฉ๋ก์œผ๋กœ ์ฝํžˆ์ง€ ์•Š๋Š”๋‹ค. 4. **accepted ์ œ์ถœ์˜ ์ „๋‹ฌ ํ™•์ธ `SKS_DELIVERY_GRACE_S` (Issue #14, `send_keys_safe`)**: `agent prompt --wait` ๊ฒฐ๊ณผ๊ฐ€ `timeout`/`agent_prompt_stalled` ์ด๋ฉด herdr ๊ฐ€ ์ž…๋ ฅ์„ ์ด๋ฏธ ์ˆ˜๋ฝํ•œ ๊ฒƒ์œผ๋กœ ๋ณด๊ณ , `SKS_DELIVERY_GRACE_S`(๊ธฐ๋ณธ 15์ดˆ) ๋™์•ˆ `agent_status` working, ์ œ์ถœ ์ „ ํ™”๋ฉด์— ์—†๋˜ busy ํ† ํฐ(`esc to interrupt`), ์ œ์ถœ ์ „ ์Šค๋ƒ…์ƒท ๋Œ€๋น„ pane ๋ณ€ํ™” ์ค‘ ํ•˜๋‚˜๋ฅผ ์ „๋‹ฌ ํ™•์ธ ์‹ ํ˜ธ๋กœ ์ธ์ •ํ•œ๋‹ค. ์‹ ํ˜ธ๊ฐ€ ์—†์œผ๋ฉด ์ข…์ „๋Œ€๋กœ rc 4 ๋กœ fail-closed ํ•˜๊ณ , ๊ทธ ๋ฐ–์˜ ์˜ค๋ฅ˜(`transport_error` ๋“ฑ)๋Š” accepted ๋กœ ์ทจ๊ธ‰ํ•˜์ง€ ์•Š๋Š”๋‹ค. ๋‹จ์ผ ์ฃผ์ž… ๊ณ„์•ฝ(์žฌ์ „์†ก ์—†์Œ)์€ ์œ ์ง€๋œ๋‹ค. 5. **๋ž˜ํผ ๋ ˆ์ง€์ŠคํŠธ๋ฆฌ ack ์œ ์˜ˆ `MAM_INJECT_ACK_GRACE_S` (Issue #14, `multi-agent-mux-delegate-job`)**: `send_keys_safe` ๊ฐ€ ์ „๋‹ฌ์„ ํ™•์ธํ•˜์ง€ ๋ชปํ•ด๋„ ์žก์„ `agent_blocked` ๋กœ ๋‹ซ๊ธฐ ์ „์— `MAM_INJECT_ACK_GRACE_S`(๊ธฐ๋ณธ 10์ดˆ) ๋™์•ˆ ๋ ˆ์ง€์ŠคํŠธ๋ฆฌ๋ฅผ ๊ด€์ธกํ•˜๊ณ , `pending` ์ด ์•„๋‹Œ ์ƒํƒœ(์—์ด์ „ํŠธ์˜ `started` ๋“ฑ)๊ฐ€ ๋ณด์ด๋ฉด ์ „๋‹ฌ๋œ ๊ฒƒ์œผ๋กœ ๋ณด๊ณ  ์ง„ํ–‰ํ•œ๋‹ค(`_inject_acknowledged`). -6. **R1 ์œ ์˜ˆ์˜ pane busy ํ† ํฐยท๋””์Šคํฌ heartbeat ์ธ์ • (Issue #14, `_agent_still_working`, `_recent_disk_heartbeat`)**: ๊ตฌ๋…์ž idle ํƒ€์ž„์•„์›ƒ ํ›„ R1 ์œ ์˜ˆ๊ฐ€ herdr `working` ์™ธ์— pane ์ตœ๊ทผ 8์ค„์˜ `esc to interrupt` ํ† ํฐ, ๊ทธ๋ฆฌ๊ณ  ์žก `events.log` ์˜ ์ตœ๊ทผ ์ด๋ฒคํŠธ(`publish_event` ๊ฐ€ ์™€์ด์–ด ๋ฐœํ–‰ ์ „์— ๋กœ์ปฌ์— ๊ธฐ๋กํ•˜๋Š” `progress` heartbeat)๋„ ์ž‘์—… ์ค‘ ๊ทผ๊ฑฐ๋กœ ๋ฐ›์•„๋“ค์ธ๋‹ค. ๊ทผ๊ฑฐ๊ฐ€ ๊ด€์ธก๋  ๋•Œ๋งˆ๋‹ค `IDLE_TIMEOUT` ๋งŒํผ์˜ ์ƒˆ ์ฐฝ์ด ์—ด๋ฆฌ๊ณ , ํ•œ ์ฐฝ ๋‚ด๋‚ด ์•„๋ฌด ๊ทผ๊ฑฐ๋„ ์—†์œผ๋ฉด ์ข…์ „๋Œ€๋กœ ๋‹ซ๋Š”๋‹ค(๋ฒฝ์‹œ๊ณ„ `TIMEOUT` ๋‚ด). idle ํƒ€์ž„์•„์›ƒ๋ณด๋‹ค ๊ธด codex ๋ฆฌ๋ทฐ, heartbeat ๊ฐ„๊ฒฉ์ด ํ•œ ๋ฒˆ idle ์ฐฝ์„ ๋„˜๊ธด ๋ฆฌ๋ทฐ, ๋ฐฑ๊ทธ๋ผ์šด๋“œ ์…ธ๋กœ ํ…Œ์ŠคํŠธ๋ฅผ ๋Œ๋ ค herdr ์— idle ๋กœ ๋ณด์ด๋Š” creator ๊ฐ€ ํ„ด ๋„์ค‘ `deadline_timeout` ์œผ๋กœ ๋‹ซํžˆ๊ณ  ์ดํ›„ `completed` ๊ฐ€ ๊ฑฐ๋ถ€๋˜๋˜ ๋ฌธ์ œ๋ฅผ ๋ฐฉ์ง€. +6. **R1 ์œ ์˜ˆ์˜ pane busy ํ† ํฐยท๋””์Šคํฌ heartbeat ์ธ์ • (Issue #14, `_agent_still_working`, `_recent_disk_heartbeat`)**: ๊ตฌ๋…์ž idle ํƒ€์ž„์•„์›ƒ ํ›„ R1 ์œ ์˜ˆ๊ฐ€ herdr `working` ์™ธ์— pane ์ตœ๊ทผ 8์ค„์˜ `esc to interrupt` ํ† ํฐ, ๊ทธ๋ฆฌ๊ณ  ์žก `events.log` ์˜ ์ตœ๊ทผ ์ด๋ฒคํŠธ(`publish_event` ๊ฐ€ ์™€์ด์–ด ๋ฐœํ–‰ ์‹œ๋„ **๋’ค**์— ์„ฑ๊ณต ์—ฌ๋ถ€์™€ ๋ฌด๊ด€ํ•˜๊ฒŒ ๋กœ์ปฌ์— ๊ธฐ๋กํ•˜๋Š” `progress` heartbeat โ€” ๋ธŒ๋กœ์ปค ์žฅ์•  ์‹œ์—๋Š” ๋ฐœํ–‰ ์žฌ์‹œ๋„ ์‹œ๊ฐ„๋งŒํผ ๋Šฆ๊ฒŒ ๊ธฐ๋ก๋œ๋‹ค)๋„ ์ž‘์—… ์ค‘ ๊ทผ๊ฑฐ๋กœ ๋ฐ›์•„๋“ค์ธ๋‹ค. ์œ ์˜ˆ์— ๋“ค์–ด๊ฐ€๋ฉด `IDLE_TIMEOUT` ์ฐฝ ํ•˜๋‚˜๊ฐ€ ์—ด๋ฆฌ๊ณ , ๊ทผ๊ฑฐ๊ฐ€ ๊ด€์ธก๋  ๋•Œ๋งˆ๋‹ค ๊ทธ ์‹œ์ ๋ถ€ํ„ฐ ์ฐฝ์ด ๋‹ค์‹œ ์—ด๋ฆฐ๋‹ค. ๋”ฐ๋ผ์„œ **์•„๋ฌด ๊ทผ๊ฑฐ๋„ ์—†๋Š” ๋ฌด์‘๋‹ต ์—์ด์ „ํŠธ๋Š” ๋งˆ์ง€๋ง‰ ์™€์ด์–ด ์ด๋ฒคํŠธ ํ›„ ์•ฝ 2ร—`IDLE_TIMEOUT` ์— ๋‹ซํžˆ๊ณ **(๋””์Šคํฌ heartbeat ๋ฅผ ์ธ์ •ํ•˜๊ธฐ ์ „์—๋Š” `IDLE_TIMEOUT`; Issue #6 ์ˆ˜์šฉ ๊ธฐ์ค€ "โ‰ค `IDLE_TIMEOUT`+5s ๋‚ด `error`"๋Š” "โ‰ค 2ร—`IDLE_TIMEOUT` + ์—ฌ์œ "๋กœ ๋ฐ”๋€๋‹ค), **heartbeat ๊ฐ„๊ฒฉ์€ ์•ฝ 2ร—`IDLE_TIMEOUT` ๊นŒ์ง€ ํ—ˆ์šฉ๋œ๋‹ค**(heartbeat ํ•˜๋‚˜๊ฐ€ `IDLE_TIMEOUT` ๋งŒํผ ์˜ค๋ž˜๋  ๋•Œ๊นŒ์ง€ ๊ทผ๊ฑฐ๋กœ ์ธ์ •๋˜๋ฏ€๋กœ). ๊ทผ๊ฑฐ๋Š” idle ์ฐฝ๋งŒ ๋Š˜๋ฆด ๋ฟ ๋ฒฝ์‹œ๊ณ„๋Š” ๋Š˜๋ฆฌ์ง€ ์•Š๋Š”๋‹ค: ๋ฃจํ”„๋Š” ๋งค ๋ฐ˜๋ณต ์‹œ๊ณ„๋กœ ๋‹ค์‹œ ์ฝ์€ `START_TIME + TIMEOUT` ์—์„œ ๋๋‚˜๊ณ , herdr ๊ด€์ธก ํ˜ธ์ถœ๋„ ๊ทธ ์‹œ๊ฐ์— ๋Š๋Š”๋‹ค(`_within_deadline`). `broker_unavailable` ๋””์Šคํฌ ์žฌ๊ด€์ธก ๋ฃจํ”„๋„ ๊ฐ™์€ ์‹œ๊ณ„ ๊ธฐ์ค€์ด๋‹ค. ์ด๋กœ์จ idle ํƒ€์ž„์•„์›ƒ๋ณด๋‹ค ๊ธด codex ๋ฆฌ๋ทฐ, heartbeat ๊ฐ„๊ฒฉ์ด ํ•œ ๋ฒˆ idle ์ฐฝ์„ ๋„˜๊ธด ๋ฆฌ๋ทฐ, ๋ฐฑ๊ทธ๋ผ์šด๋“œ ์…ธ๋กœ ํ…Œ์ŠคํŠธ๋ฅผ ๋Œ๋ ค herdr ์— idle ๋กœ ๋ณด์ด๋Š” creator ๊ฐ€ ํ„ด ๋„์ค‘ `deadline_timeout` ์œผ๋กœ ๋‹ซํžˆ๊ณ  ์ดํ›„ `completed` ๊ฐ€ ๊ฑฐ๋ถ€๋˜๋˜ ๋ฌธ์ œ๋ฅผ ๋ง‰๋Š”๋‹ค. #### โœ… ํ’ˆ์งˆ ๊ฒ€์ฆ - **T1-7 ํŠธ๋ฆฌ๊ฑฐ ๋ณ€๊ฒฝ** (`tests/test_issue6_fail_closed.py`): ์ฃผ์ž… ์‹คํŒจ ์œ ๋ฐœ๊ฐ’์„ `prompt_wait_result=timeout` โ†’ `transport_error` ๋กœ ๋ณ€๊ฒฝ(Issue #14 ์ดํ›„ `timeout` ์€ accepted ์ œ์ถœ์ด๋ฏ€๋กœ ๋” ์ด์ƒ ํ™•์ • ์‹คํŒจ๊ฐ€ ์•„๋‹˜)ํ•˜๊ณ  `MAM_INJECT_ACK_GRACE_S=1` ๋กœ ๋Œ€๊ธฐ๋ฅผ ๋‹จ์ถ•. -- **์‹ ๊ทœ ํ…Œ์ŠคํŠธ 17๊ฐœ**: `tests/test_issue9_server_env.py` 8๊ฐœ(๋งˆ์ปค ์ œ๊ฑฐ, `MAM_NO_AUTOSTART` ๋ถ€ํŠธ์ŠคํŠธ๋žฉ ์ƒ๋žตยทํ˜ธ์ถœ ์ „๋‹ฌ, status ์กฐํšŒ ๋ฌด๊ธฐ๋™, ์ •์  opt-out, `ls` ๋ฒˆ์—ญ(์ตœ์†Œยทherdr 0.9 ์‹ค์ œ ์˜ค๋ฅ˜ ๋ด‰ํˆฌ), ์„ฑ๊ณต ๋ชฉ๋ก ์† `server_not_running` ๋ฌธ์ž์—ด ๋น„์˜คํŒ, ๊ทธ ๋ฐ–์˜ ์‹คํŒจ unknown ์œ ์ง€, reconcile drift A ๋น„๋ฐœ์ƒ), `tests/test_issue14_delivery_ack.py` 9๊ฐœ(busy ํ† ํฐยทpane ๋ณ€ํ™” ํ™•์ธ, ๋ฌด์‹ ํ˜ธ fail-closed, ์„ ํ–‰ busy ํ† ํฐ ๋ฐฐ์ œ, `transport_error` ๋น„์ˆ˜์šฉ, mock herdr timeout ํ™•์ธ, ๋ž˜ํผ ๋ ˆ์ง€์ŠคํŠธ๋ฆฌ ack, idle ํƒ€์ž„์•„์›ƒ pane busy ์œ ์˜ˆ, idle ํƒ€์ž„์•„์›ƒ ๋””์Šคํฌ heartbeat ์œ ์˜ˆ). +- **์‹ ๊ทœ ํ…Œ์ŠคํŠธ 19๊ฐœ**: `tests/test_issue9_server_env.py` 9๊ฐœ(๋งˆ์ปค ์ œ๊ฑฐ, `MAM_NO_AUTOSTART` ๋ถ€ํŠธ์ŠคํŠธ๋žฉ ์ƒ๋žตยทํ˜ธ์ถœ ์ „๋‹ฌ, status ์กฐํšŒ ๋ฌด๊ธฐ๋™, ์ •์  opt-out, `ls` ๋ฒˆ์—ญ(์ตœ์†Œยทherdr 0.9 ์‹ค์ œ ์˜ค๋ฅ˜ ๋ด‰ํˆฌยทstdout ๋ด‰ํˆฌ), ์„ฑ๊ณต ๋ชฉ๋ก ์† `server_not_running` ๋ฌธ์ž์—ด ๋น„์˜คํŒ, ๊ทธ ๋ฐ–์˜ ์‹คํŒจ unknown ์œ ์ง€(stderrยทstdout), reconcile drift A ๋น„๋ฐœ์ƒ, ๋‹ค๋ฅธ ์‹คํŒจ ์‹œ reconcile `herdr_confirmed=False`), `tests/test_issue14_delivery_ack.py` 10๊ฐœ(busy ํ† ํฐยทpane ๋ณ€ํ™” ํ™•์ธ, ๋ฌด์‹ ํ˜ธ fail-closed, ์„ ํ–‰ busy ํ† ํฐ ๋ฐฐ์ œ, `transport_error` ๋น„์ˆ˜์šฉ, mock herdr timeout ํ™•์ธ, ๋ž˜ํผ ๋ ˆ์ง€์ŠคํŠธ๋ฆฌ ack, idle ํƒ€์ž„์•„์›ƒ pane busy ์œ ์˜ˆ, idle ํƒ€์ž„์•„์›ƒ ๋””์Šคํฌ heartbeat ์œ ์˜ˆ, heartbeat ๊ฐ€ ์ด์–ด์ ธ๋„ ๋ฒฝ์‹œ๊ณ„ `TIMEOUT` ์•ˆ์—์„œ ์ข…๋ฃŒ). - **ํ…Œ์ŠคํŠธ ๊ธฐ๋Œ€๊ฐ’ ์ •์ •**: `tests/test_a4_adapter_contract.py` ๊ฐ€ `4d444ce` ์˜ agy `exit_key=/exit` ๋ณ€๊ฒฝ์„ ๋ฐ˜์˜ํ•˜๋„๋ก ์ˆ˜์ •(๊ทธ๋™์•ˆ ์ „์ฒด ์Šค์œ„ํŠธ์—์„œ 1๊ฑด ์‹คํŒจํ•˜๋˜ ๋ฌธ์ œ ํ•ด์†Œ). - **์‹ค์ธก (์ปค๋ฐ‹ `497633f` ๊ธฐ๋ก)**: ์ƒˆ๋กœ ๋ถ€ํŠธ์ŠคํŠธ๋žฉํ•œ ์„œ๋ฒ„์— ๋งˆ์ปค๊ฐ€ ์—†๊ณ  claude pane ์˜ transcript ์ €์žฅ์ด ๋ณต๊ตฌ๋จ, codex ์žก `d04ebcb5` ์˜ `started`/`completed` ๊ฐ€ `agent_blocked` ์—†์ด ์ˆ˜๋ฝ๋จ. diff --git a/tests/test_issue14_delivery_ack.py b/tests/test_issue14_delivery_ack.py index 874b838..9223971 100644 --- a/tests/test_issue14_delivery_ack.py +++ b/tests/test_issue14_delivery_ack.py @@ -366,3 +366,77 @@ def test_wrapper_idle_timeout_grace_accepts_disk_heartbeat(tmp_path): job_data = json.loads((reg_dir / f"{jid}.json").read_text()) assert job_data.get("status") == "completed", f"status={job_data.get('status')}\n{stdout}\n{stderr}" assert proc.returncode == 0, f"expected rc=0 while heartbeats kept landing, got {proc.returncode}\n{stdout}\n{stderr}" + + +def test_wrapper_idle_grace_never_outlives_the_wall_clock(tmp_path): + """Heartbeats may extend the idle window, never the overall --timeout. + Fresh heartbeats land in events.log every second for the whole run, and + every python probe the wrapper makes is slowed down (herdr-RPC-like + latency). Counting sleeps instead of reading the clock let the grace loop + run about twice as long as TIMEOUT; the job must instead close as + deadline_timeout within TIMEOUT plus a small close/publish margin.""" + import threading + + timeout_s, idle_s = 20, 4 + reg_dir = tmp_path / "jobs" + reg_dir.mkdir(parents=True, exist_ok=True) + slow_py = tmp_path / "slow-python" + slow_py.write_text(f'#!/bin/sh\nsleep 0.7\nexec "{sys.executable}" "$@"\n') + slow_py.chmod(0o755) + env = _base_env(tmp_path, {"DELEGATE_JOB_PYTHON": slow_py}) + + started = time.time() + proc = subprocess.Popen( + [ + "bash", str(WRAPPER), "submit", + "--agent", "human", + "--prompt", "issue 14 wall clock", + "--registry-dir", str(reg_dir), + "--workdir", str(tmp_path), + "--timeout", str(timeout_s), + "--idle-timeout", str(idle_s), + ], + cwd=str(tmp_path), env=env, stdout=subprocess.PIPE, stderr=subprocess.PIPE, text=True, + ) + + jid = "" + for _ in range(200): + job_files = list(reg_dir.glob("*.json")) + if job_files: + jid = job_files[0].stem + break + time.sleep(0.1) + assert jid, "job was not registered" + events_log = reg_dir / f"{jid}.events.log" + + stop = threading.Event() + + def keep_heartbeating(): + # The same line shape publish_event appends; only its timestamp matters + # to _recent_disk_heartbeat. + seq = 10_000 + while not stop.is_set(): + seq += 1 + line = {"schema_version": 1, "seq": seq, "job_id": jid, "event": "progress", + "timestamp": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime()), + "detail": "still working", "data": {}} + with open(events_log, "a") as fh: + fh.write(json.dumps(line) + "\n") + stop.wait(1) + + beat = threading.Thread(target=keep_heartbeating, daemon=True) + beat.start() + try: + stdout, stderr = proc.communicate(timeout=120) + finally: + stop.set() + elapsed = time.time() - started + + job_data = json.loads((reg_dir / f"{jid}.json").read_text()) + assert proc.returncode == 2, f"expected the deadline_timeout path (rc=2), got {proc.returncode}\n{stderr}" + assert job_data.get("status") == "error", f"status={job_data.get('status')}\n{stderr}" + # The heartbeats were honoured: the job was not closed after the first idle + # window, it stayed open up to the wall clock ... + assert elapsed >= timeout_s - 1, f"closed before the wall clock: {elapsed:.1f}s\n{stderr}" + # ... and not a moment past it beyond closing and publishing the error. + assert elapsed <= timeout_s + 12, f"idle grace outlived --timeout {timeout_s}s: {elapsed:.1f}s\n{stderr}" diff --git a/tests/test_issue9_server_env.py b/tests/test_issue9_server_env.py index 84be8d5..500dfb2 100644 --- a/tests/test_issue9_server_env.py +++ b/tests/test_issue9_server_env.py @@ -195,18 +195,32 @@ def test_reconcile_and_status_opt_out_of_autostart_statically(): f"{script.name} must opt out of the shim's server bootstrap" -@pytest.mark.parametrize("envelope", [ - {"error": {"code": "server_not_running"}}, - REAL_DOWN_ENVELOPE, -], ids=["minimal", "herdr-0.9"]) -def test_ls_reports_down_server_as_no_server_running(mam_sandbox, envelope): +def _fail_with(text: str, stream: str) -> str: + """Fake `agent list` body: write `text` to `stream` and exit 1.""" + return f'sys.{stream}.write({json.dumps(text)} + "\\n"); sys.exit(1)' + + +# reconcile.sh reads a nonzero `ls` whose stderr contains any of these as a +# confirmed-EMPTY server (`is_empty`); anything else as unknown. +RECONCILE_EMPTY_PHRASES = ("no server running", "no sessions", "failed to connect") + +# An unrelated structured failure whose message happens to mention the code. +TRANSPORT_ERROR = json.dumps({"error": {"code": "transport_error", + "message": "socket reset while probing server_not_running"}}) + + +@pytest.mark.parametrize("envelope,stream", [ + ({"error": {"code": "server_not_running"}}, "stderr"), + (REAL_DOWN_ENVELOPE, "stderr"), + ({"error": {"code": "server_not_running"}}, "stdout"), +], ids=["minimal", "herdr-0.9", "minimal-on-stdout"]) +def test_ls_reports_down_server_as_no_server_running(mam_sandbox, envelope, stream): """reconcile.sh treats a nonzero `ls` as 'empty' only when stderr says 'no server running'; anything else flips herdr_confirmed=False for every server. The shim must therefore translate server_not_running explicitly.""" env = _install_fake_herdr(mam_sandbox) env["MAM_NO_AUTOSTART"] = "1" - _fake_agent_list(mam_sandbox, - f'sys.stderr.write({json.dumps(json.dumps(envelope))} + "\\n"); sys.exit(1)') + _fake_agent_list(mam_sandbox, _fail_with(json.dumps(envelope), stream)) res = _shim_ls(mam_sandbox, env, "down-srv") assert res.returncode != 0 @@ -229,51 +243,75 @@ def test_ls_lists_agents_whose_names_contain_server_not_running(mam_sandbox): assert names == ["server_not_running-codex", "creator-claude-01"], res.stdout -@pytest.mark.parametrize("stderr_text", [ - json.dumps({"error": {"code": "transport_error", - "message": "socket reset while probing server_not_running"}}), - "warning: server_not_running cache entry is stale", - "", -], ids=["other-code", "plain-text", "empty"]) -def test_ls_leaves_other_failures_unknown(mam_sandbox, stderr_text): - """Only the structured code means "down". Any other failure keeps the - unknown path (nonzero exit without 'no server running'), so reconcile - drops herdr_confirmed instead of reading a confirmed-empty server.""" +@pytest.mark.parametrize("text,stream", [ + (TRANSPORT_ERROR, "stderr"), + (TRANSPORT_ERROR, "stdout"), + ("warning: server_not_running cache entry is stale", "stderr"), + ("", "stderr"), +], ids=["other-code", "other-code-on-stdout", "plain-text", "empty"]) +def test_ls_leaves_other_failures_unknown(mam_sandbox, text, stream): + """Only the structured code means "down". Any other failure must stay + unknown - nonzero exit, no empty-server phrase - wherever its error + document lands. On stdout it used to reach the list parser, which read a + JSON error without result.agents as a successful EMPTY list (rc 0).""" env = _install_fake_herdr(mam_sandbox) env["MAM_NO_AUTOSTART"] = "1" - _fake_agent_list(mam_sandbox, - f'sys.stderr.write({json.dumps(stderr_text)} + "\\n"); sys.exit(1)') + _fake_agent_list(mam_sandbox, _fail_with(text, stream)) res = _shim_ls(mam_sandbox, env, "flaky-srv") - assert res.returncode != 0 - assert "no server running" not in res.stderr, res.stderr + assert res.returncode != 0, f"a failed list must not exit 0: {res.stdout!r} {res.stderr!r}" + for phrase in RECONCILE_EMPTY_PHRASES: + assert phrase not in res.stderr.lower(), res.stderr assert res.stdout.strip() == "" +def _write_running_rows(sandbox: Path, names, server: str = "live-srv") -> None: + rows = "".join( + f" - name: {name}\n" + " status: running\n" + f" herdr_session: {server}\n" + " pane:\n" + " cwd: /tmp/nonexistent-workspace\n" + for name in names + ) + (sandbox / ".mam" / "agent-sessions.yaml").write_text("herdr_sessions:\n" + rows) + + +def _reconcile_dry_run(sandbox: Path, env: dict) -> dict: + reconcile = sandbox / "skills" / "multi-agent-mux-monitor" / "scripts" / "reconcile.sh" + res = subprocess.run(["bash", str(reconcile), "--once", "--emit-diff", "--dry-run"], + capture_output=True, text=True, cwd=str(sandbox), env=env, timeout=120) + assert res.returncode == 0, res.stderr + return json.loads(res.stdout) + + def test_reconcile_keeps_live_rows_when_a_name_contains_server_not_running(mam_sandbox): """End to end through reconcile.sh: the server answers a successful list in which the down-server code appears as data. Both registered rows must stay alive with herdr_confirmed intact, so drift A cannot mark them terminated.""" env = _install_fake_herdr(mam_sandbox) _fake_agent_list(mam_sandbox, f"print({json.dumps(json.dumps(LISTING_WITH_SUBSTRING))})") - rows = "".join( - f" - name: {name}\n" - " status: running\n" - " herdr_session: live-srv\n" - " pane:\n" - " cwd: /tmp/nonexistent-workspace\n" - for name in ("server_not_running-codex", "creator-claude-01") - ) - (mam_sandbox / ".mam" / "agent-sessions.yaml").write_text("herdr_sessions:\n" + rows) - reconcile = mam_sandbox / "skills" / "multi-agent-mux-monitor" / "scripts" / "reconcile.sh" + _write_running_rows(mam_sandbox, ("server_not_running-codex", "creator-claude-01")) - res = subprocess.run(["bash", str(reconcile), "--once", "--emit-diff", "--dry-run"], - capture_output=True, text=True, cwd=str(mam_sandbox), env=env, timeout=120) - assert res.returncode == 0, res.stderr - - report = json.loads(res.stdout) + report = _reconcile_dry_run(mam_sandbox, env) assert report["herdr_confirmed"] is True, report alive = set(report["herdr_sessions_alive"]) assert {"server_not_running-codex|live-srv", "creator-claude-01|live-srv"} <= alive, alive drift_a = [d for d in report["drifts"] if d.get("class") == "A"] assert not drift_a, drift_a + + +def test_reconcile_treats_other_list_failures_as_unknown(mam_sandbox): + """End to end through reconcile.sh: a server whose `agent list` fails with + an unrelated structured error on stdout must drop herdr_confirmed, so + drift A never marks its live row terminated.""" + env = _install_fake_herdr(mam_sandbox) + _fake_agent_list(mam_sandbox, _fail_with(TRANSPORT_ERROR, "stdout")) + _write_running_rows(mam_sandbox, ("creator-claude-01",)) + + report = _reconcile_dry_run(mam_sandbox, env) + assert report["herdr_confirmed"] is False, report + drift_a = [d for d in report["drifts"] if d.get("class") == "A"] + assert not drift_a, drift_a + terminated = [a for a in report.get("actions", []) if str(a).startswith("terminated")] + assert not terminated, terminated