feat(issue-33): the job budget travels and the two clocks carry different labels
- wrapper: TIMEOUT falls back to MAM_JOB_TIMEOUT_S (--timeout > env > 3600); an invalid value warns and keeps 3600. - loop: --job-timeout <sec> (run_loop.sh passes it on; refused in the legacy shell loop). The runner always hands the wrapper --timeout, so the budget the wrapper registers is the one its wait caps come from. - runner: wait_for_job and the MAM_CHILD_WAIT_S default are budget + 300 s (MAM_WAIT_GRACE_S), today's 3900 with no option; an explicit MAM_CHILD_WAIT_S still wins. - subscriber: the wall-clock budget returns 4 (RC_WALL_CLOCK), silence keeps 2 (RC_NO_EVENT). The wrapper maps both to caller rc 2 and labels the close from the rc: wall_clock_timeout vs deadline_timeout; the disk-heartbeat grace that ends on the deadline is the wall clock too. - registry close accepts wall_clock_timeout (engine: -> error); the remote runner's deadline and command-timeout details lead with wall_clock_timeout; the sub-job table files it CLOSED-UNCONFIRMED (first token, colon stripped). Test expectations changed only where the contract changed: the loop's contract_args now starts with --timeout, the subscriber's exit-code docstring names rc 2/4, and the registry --help capture lists the new close kind. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
GodopuandClaude Opus 5.5 committed
1 parent
8ea65bb238
commit
ec9586bb9b
11 files changed
+409
-23
No files matched your search
@@ -47,7 +47,8 @@ REQUEST_TO_STATUS = {
|
||||
"completed": "completed",
|
||||
"error": "error",
|
||||
"cancelled": "cancelled",
|
||||
"deadline_timeout": "error",
|
||||
"deadline_timeout": "error", # no event for K x N (subscriber rc 2)
|
||||
"wall_clock_timeout": "error", # the job budget ran out (subscriber rc 4, Issue #33)
|
||||
"merge": None,
|
||||
# Operator-authority requests. The wrapper drives multi-iteration delegation
|
||||
# (`submit --type loop|discuss`) by re-dispatching a finished job to the next
|
||||
|
||||
@@ -19,7 +19,9 @@ stdout = event lines only. Diagnostics go to stderr via logging.
|
||||
Exit codes:
|
||||
0 all watched jobs reached ``completed``
|
||||
1 any watched job reached ``error``
|
||||
2 timed out (wall-clock or idle) before all jobs finished
|
||||
2 no event for the idle window (K x N) - the wrapper labels it deadline_timeout
|
||||
3 broker unreachable
|
||||
4 the wall-clock budget (--timeout) ran out - the wrapper labels it wall_clock_timeout
|
||||
"""
|
||||
from __future__ import annotations
|
||||
|
||||
@@ -47,6 +49,12 @@ logger = logging.getLogger("delegate_job.job_subscriber")
|
||||
TERMINAL_EVENTS = ("completed", "error")
|
||||
TERMINAL_STATUSES = ("completed", "error", "cancelled")
|
||||
STATE_EVENT = "state"
|
||||
# Issue #33: which clock ended the wait. The wrapper maps both to a timeout
|
||||
# (caller rc 2) and labels the close from them: rc 2 -> deadline_timeout
|
||||
# (no event for the idle window, K x N), rc 4 -> wall_clock_timeout (the job
|
||||
# budget, --timeout, ran out while events may still have been arriving).
|
||||
RC_NO_EVENT = 2
|
||||
RC_WALL_CLOCK = 4
|
||||
|
||||
|
||||
def _format_line(topic: str, payload: Dict[str, Any]) -> str:
|
||||
@@ -473,7 +481,7 @@ def _run_subscriber(args) -> int:
|
||||
break
|
||||
logger.error("wall-clock timeout (%.0fs); still pending: %s",
|
||||
wall_timeout, ", ".join(sorted(pending)))
|
||||
return 2
|
||||
return RC_WALL_CLOCK
|
||||
if not subscribed:
|
||||
last_event = now
|
||||
idle_left = (idle_timeout if first_event_seen else idle_timeout + ack_timeout) - (now - last_event)
|
||||
@@ -483,7 +491,7 @@ def _run_subscriber(args) -> int:
|
||||
break
|
||||
logger.error("idle timeout (%.0fs, no events); still pending: %s",
|
||||
idle_timeout, ", ".join(sorted(pending)))
|
||||
return 2
|
||||
return RC_NO_EVENT
|
||||
wait = min(wall_deadline - now, idle_left, 1.0)
|
||||
try:
|
||||
topic, payload = watcher.events.get(timeout=wait)
|
||||
|
||||
@@ -419,9 +419,9 @@ def _build_parser() -> argparse.ArgumentParser:
|
||||
p_update.add_argument("--attempt-id", type=int, default=None)
|
||||
p_update.add_argument("--role", default=None)
|
||||
|
||||
p_close = sub.add_parser("close", help="close a job with deadline_timeout or cancelled")
|
||||
p_close = sub.add_parser("close", help="close a job with deadline_timeout, wall_clock_timeout or cancelled")
|
||||
p_close.add_argument("--job", required=True)
|
||||
p_close.add_argument("--request", required=True, choices=["deadline_timeout", "cancelled"])
|
||||
p_close.add_argument("--request", required=True, choices=["deadline_timeout", "wall_clock_timeout", "cancelled"])
|
||||
p_close.add_argument("--detail", default=None)
|
||||
p_close.add_argument("--expect-dispatch-token", default=None)
|
||||
|
||||
|
||||
@@ -331,7 +331,7 @@ def handle_dispatch(d: Dict[str, Any], registry_dir: str, session: str,
|
||||
timeout = float(job.get("timeout_sec", 3600))
|
||||
rc, out, err, timed_out = _run_agent_command(exec_cmd, env, timeout)
|
||||
if timed_out:
|
||||
detail = "agent command exceeded timeout_sec {}".format(int(timeout))
|
||||
detail = "wall_clock_timeout: agent command exceeded timeout_sec {}".format(int(timeout))
|
||||
else:
|
||||
tail = (out or "").strip().splitlines()
|
||||
detail = tail[-1][:200] if tail else "exit {}".format(rc)
|
||||
@@ -349,7 +349,7 @@ def handle_dispatch(d: Dict[str, Any], registry_dir: str, session: str,
|
||||
if cur.get("status") in ("completed", "error", "cancelled"):
|
||||
return 0 if cur.get("status") == "completed" else 1
|
||||
time.sleep(1.0)
|
||||
_publish(jid, registry_dir, "error", "deadline_timeout (remote runner)", d)
|
||||
_publish(jid, registry_dir, "error", "wall_clock_timeout (remote runner)", d)
|
||||
return 2
|
||||
|
||||
|
||||
|
||||
@@ -33,7 +33,7 @@ UNAVAILABLE_MARKER = "!!! CHANGE SET UNAVAILABLE !!!" # diff_collect.sh MAM_DIF
|
||||
# not interrupted and may still be writing; a job that never reached its agent
|
||||
# was cancelled before injection.
|
||||
TERMINAL = ("completed", "error", "cancelled")
|
||||
ORCHESTRATOR_CLOSED = ("deadline_timeout", "agent_blocked")
|
||||
ORCHESTRATOR_CLOSED = ("deadline_timeout", "wall_clock_timeout", "agent_blocked")
|
||||
SUBJOB_RULE = ("규칙: 열린(OPEN)·미확인 종결(CLOSED-UNCONFIRMED)·실패 하위 잡이 하나라도 있으면 산출물을 미완으로 보고 "
|
||||
"[VERDICT: NOT PASS] 를 내십시오. creator 리포트가 해당 부분의 대체 완료를 입증하면 예외입니다. "
|
||||
"CLOSED-UNCONFIRMED 는 오케스트레이터가 마감으로 닫은 잡이며 그 에이전트는 계속 일하고 있을 수 있습니다. "
|
||||
@@ -121,6 +121,7 @@ class LoopRunner:
|
||||
self.reviewer_list: Optional[str] = None
|
||||
self.all_reviewers: bool = False
|
||||
self.max_loop: int = 3
|
||||
self.job_timeout: Optional[int] = None
|
||||
self.max_rebut: int = 1
|
||||
self.verbose: bool = False
|
||||
self.cleanup: bool = False
|
||||
@@ -139,6 +140,7 @@ class LoopRunner:
|
||||
" --all-reviewer Enforce PASS verdict from all active reviewer sessions",
|
||||
" --max-loop N Max execution-review corrective loop runs (default: 3)",
|
||||
" --max-rebut N Max rebuttal attempts per review iteration (default: 1, 0: disabled)",
|
||||
" --job-timeout <sec> Budget of each delegated job (default: $MAM_JOB_TIMEOUT_S or 3600)",
|
||||
" --verbose Print detailed execution timeline traces",
|
||||
" --cleanup Purge temporary job directories upon success",
|
||||
" --worktree <path> Source worktree for diff/base/head (control plane stays here)",
|
||||
@@ -209,6 +211,12 @@ class LoopRunner:
|
||||
sys.exit(1)
|
||||
self.max_loop = int(args[i + 1])
|
||||
i += 2
|
||||
elif arg == "--job-timeout":
|
||||
if i + 1 >= len(args) or not re.match(r"^[0-9]+$", args[i + 1]) or int(args[i + 1]) <= 0:
|
||||
print("ERROR: --job-timeout requires a positive non-zero integer.", file=sys.stderr)
|
||||
sys.exit(1)
|
||||
self.job_timeout = int(args[i + 1])
|
||||
i += 2
|
||||
elif arg == "--max-rebut":
|
||||
if i + 1 >= len(args) or not re.match(r"^[0-9]+$", args[i + 1]):
|
||||
print("ERROR: --max-rebut requires a non-negative integer.", file=sys.stderr)
|
||||
@@ -454,8 +462,10 @@ class LoopRunner:
|
||||
def contract_args(self) -> List[str]:
|
||||
"""Liveness-contract knobs passed through to every delegate job
|
||||
(Issue #18): MAM_HEARTBEAT_SEC (N), MAM_HEARTBEAT_MISSES (K),
|
||||
MAM_ACK_TIMEOUT_S (T). The wrapper derives --idle-timeout as K x N."""
|
||||
args: List[str] = []
|
||||
MAM_ACK_TIMEOUT_S (T). The wrapper derives --idle-timeout as K x N.
|
||||
Issue #33: the job budget is always passed explicitly, so the budget
|
||||
the wrapper registers is the one job_wait_s was derived from."""
|
||||
args: List[str] = ["--timeout", str(self.job_budget)]
|
||||
for env_name, flag in (("MAM_HEARTBEAT_SEC", "--heartbeat"),
|
||||
("MAM_HEARTBEAT_MISSES", "--heartbeat-misses"),
|
||||
("MAM_ACK_TIMEOUT_S", "--ack-timeout")):
|
||||
@@ -572,8 +582,27 @@ class LoopRunner:
|
||||
return job_id
|
||||
return None
|
||||
|
||||
def wait_for_job(self, job_id: str, max_wait: int = 3900, check_interval: float = 1.0) -> bool:
|
||||
@property
|
||||
def job_budget(self) -> int:
|
||||
"""Issue #33: --job-timeout > $MAM_JOB_TIMEOUT_S (positive integer) > 3600."""
|
||||
if self.job_timeout:
|
||||
return self.job_timeout
|
||||
env = os.environ.get("MAM_JOB_TIMEOUT_S", "")
|
||||
return int(env) if env.isdigit() and int(env) > 0 else 3600
|
||||
|
||||
@property
|
||||
def job_wait_s(self) -> int:
|
||||
"""Wait cap for a job and its sub-jobs: budget + MAM_WAIT_GRACE_S (300,
|
||||
today's 3900 - 3600). The grace covers the wrapper's close/publish tail
|
||||
after the wall clock and the 1 s record poll; it is not proportional
|
||||
to the budget because nothing observed would justify that."""
|
||||
grace = os.environ.get("MAM_WAIT_GRACE_S", "")
|
||||
return self.job_budget + (int(grace) if grace.isdigit() else 300)
|
||||
|
||||
def wait_for_job(self, job_id: str, max_wait: Optional[float] = None, check_interval: float = 1.0) -> bool:
|
||||
"""Blocking wait for job completion or error with safety timeout."""
|
||||
if max_wait is None:
|
||||
max_wait = self.job_wait_s
|
||||
if job_id in self.failed_submit_jobs:
|
||||
# Submit command for this job failed (rc!=0). Cap wait to 5s to avoid 3900s hang
|
||||
max_wait = min(max_wait, 5.0)
|
||||
@@ -644,7 +673,10 @@ class LoopRunner:
|
||||
A terminal record is not a stopped agent (a deadline close does not
|
||||
interrupt it); that is left to the sub-job table and the stale-review
|
||||
guard, since nothing signals such an agent's end."""
|
||||
max_wait = float(os.environ.get("MAM_CHILD_WAIT_S", "3900"))
|
||||
child_env = os.environ.get("MAM_CHILD_WAIT_S")
|
||||
max_wait = float(child_env) if child_env else float(self.job_wait_s)
|
||||
wait_src = "MAM_CHILD_WAIT_S" if child_env else \
|
||||
f"MAM_CHILD_WAIT_S default: job budget {self.job_budget} + {self.job_wait_s - self.job_budget}"
|
||||
tree_max = int(os.environ.get("MAM_JOB_TREE_MAX", "50"))
|
||||
since = self._created_at(root)
|
||||
start = time.time()
|
||||
@@ -667,7 +699,7 @@ class LoopRunner:
|
||||
+ " ".join(f"{r.get('job_id')}({r.get('agent_session', '?')}, {r.get('status')})" for r in open_jobs))
|
||||
last = now
|
||||
if time.time() - start >= max_wait:
|
||||
log_warn(f"sub-job wait for {root} ended after {int(max_wait)}s (MAM_CHILD_WAIT_S) with "
|
||||
log_warn(f"sub-job wait for {root} ended after {int(max_wait)}s ({wait_src}) with "
|
||||
f"{len(open_jobs)} open; reviewers see them as OPEN")
|
||||
return False
|
||||
time.sleep(interval)
|
||||
@@ -693,7 +725,7 @@ class LoopRunner:
|
||||
return "completed", reason or "-"
|
||||
# merge review R2 (codex): the remote runner phrases its deadline as
|
||||
# "deadline_timeout (remote runner)", so the kind is the first word
|
||||
closed_kind = reason.split(" ", 1)[0] if reason else ""
|
||||
closed_kind = reason.split(" ", 1)[0].rstrip(":") if reason else ""
|
||||
if closed_kind in ORCHESTRATOR_CLOSED or (status == "error" and not reason):
|
||||
# no recorded reason is not the agent's own report either
|
||||
return "CLOSED-UNCONFIRMED", reason or "-"
|
||||
|
||||
@@ -111,7 +111,7 @@ usage() {
|
||||
multi-agent-mux-delegate-job <command> [options]
|
||||
|
||||
submit --agent <name> (--prompt <text> | --prompt-file <path>) [--workdir <dir>] [--agent-session <label>]
|
||||
[--timeout <sec>] [--idle-timeout <sec>] [--validate <script>]
|
||||
[--timeout <sec> (default: $MAM_JOB_TIMEOUT_S or 3600)] [--idle-timeout <sec>] [--validate <script>]
|
||||
[--heartbeat <sec>] [--heartbeat-misses <count>] [--ack-timeout <sec>]
|
||||
[--registry-dir <dir>] [--dry-run] [--role <role_name>]
|
||||
[--type <direct|loop|discuss>] [--reviewer <reviewer_agent>]
|
||||
@@ -140,6 +140,14 @@ EOF
|
||||
# ---- arg parsing helpers --------------------------------------------------
|
||||
AGENT="claude-code"; PROMPT=""; PROMPT_FILE=""; WORKDIR="$(pwd)"; AGENT_SESSION="herdr:claude"
|
||||
TIMEOUT=3600; IDLE_TIMEOUT=""; VALIDATE=""; DRY_RUN=0
|
||||
# Issue #33: the job budget falls back to $MAM_JOB_TIMEOUT_S (--timeout > env > 3600).
|
||||
if [[ -n "${MAM_JOB_TIMEOUT_S:-}" ]]; then
|
||||
if [[ "$MAM_JOB_TIMEOUT_S" =~ ^[0-9]+$ && "$MAM_JOB_TIMEOUT_S" -gt 0 ]]; then
|
||||
TIMEOUT="$MAM_JOB_TIMEOUT_S"
|
||||
else
|
||||
echo "WARNING: MAM_JOB_TIMEOUT_S=$MAM_JOB_TIMEOUT_S ignored (not a positive integer); using 3600" >&2
|
||||
fi
|
||||
fi
|
||||
# Issue #18 liveness contract (N / K / T). An unset --idle-timeout derives K x N.
|
||||
HEARTBEAT_SEC="${MAM_HEARTBEAT_SEC:-30}"; HEARTBEAT_MISSES="${MAM_HEARTBEAT_MISSES:-4}"; ACK_TIMEOUT="${MAM_ACK_TIMEOUT_S:-180}"
|
||||
JOB_ID=""; REGISTRY_DIR="$REGISTRY_DIR_DEFAULT"; DELEGATE_ROLE="Worker"
|
||||
@@ -803,7 +811,7 @@ _rc_for() {
|
||||
}
|
||||
|
||||
finalize_unfinished() {
|
||||
local job_id="$1" job_status="$2" sub_rc="$3" phase="${4:-}"
|
||||
local job_id="$1" job_status="$2" sub_rc="$3" phase="${4:-}" FINALIZE_CLOCK=""
|
||||
if [ "${MAM_DELEGATE_FAIL_CLOSED:-1}" = "0" ]; then
|
||||
return 0
|
||||
fi
|
||||
@@ -885,9 +893,16 @@ finalize_unfinished() {
|
||||
[ "$left" -le 0 ] && break
|
||||
sleep 1
|
||||
done
|
||||
[ "$(date +%s)" -ge "$deadline" ] && FINALIZE_CLOCK="wall"
|
||||
fi
|
||||
|
||||
# Issue #33: the subscriber's rc says which clock ran out (4 wall clock,
|
||||
# 2 no event); the disk-heartbeat grace above that ends on the deadline is
|
||||
# the wall clock too. bash only carries the label.
|
||||
local clock="${FINALIZE_CLOCK:-idle}"
|
||||
[ "$sub_rc" = "4" ] && clock="wall"
|
||||
local close_req="deadline_timeout"
|
||||
[ "$clock" = "wall" ] && [ "$phase" != "inject" ] && close_req="wall_clock_timeout"
|
||||
local detail=""
|
||||
if [ "$phase" = "preflight" ] || [ "$phase" = "idle_wait" ]; then
|
||||
close_req="cancelled"
|
||||
@@ -896,6 +911,7 @@ finalize_unfinished() {
|
||||
[ "$phase" = "preflight" ] && [ -n "${PREFLIGHT_REASON:-}" ] && detail="$PREFLIGHT_REASON"
|
||||
fi
|
||||
|
||||
[ "$close_req" != "cancelled" ] && echo "finalize: $job_id closed by $([ "$clock" = "wall" ] && echo wall_clock || echo no_event) clock (budget ${TIMEOUT}s / idle ${IDLE_TIMEOUT}s)" >&2
|
||||
local close_args=(--job "$job_id" --request "$close_req")
|
||||
[ -n "$detail" ] && close_args+=(--detail "$detail")
|
||||
[ -n "${_disp_tok:-}" ] && close_args+=(--expect-dispatch-token "$_disp_tok")
|
||||
@@ -925,7 +941,7 @@ finalize_unfinished() {
|
||||
if [ "$close_req" = "cancelled" ]; then
|
||||
"$PY" "$SCRIPT_DIR/scripts/publish_event.py" --registry-dir "$REGISTRY_DIR" --job "$job_id" --event cancelled --detail "$detail" ${disp_arg[@]+"${disp_arg[@]}"} 2>/dev/null || true
|
||||
elif [ "$sub_rc" -ne 1 ] || [ "$phase" = "inject" ]; then
|
||||
local err_detail="deadline_timeout"
|
||||
local err_detail="$close_req"
|
||||
[ "$phase" = "inject" ] && err_detail="agent_blocked"
|
||||
"$PY" "$SCRIPT_DIR/scripts/publish_event.py" --registry-dir "$REGISTRY_DIR" --job "$job_id" --event error --detail "$err_detail" ${disp_arg[@]+"${disp_arg[@]}"} 2>/dev/null || true
|
||||
fi
|
||||
|
||||
@@ -39,6 +39,7 @@ LOOP_REVIEW_ONLY=0
|
||||
LOOP_REVIEW_ISOLATION=""
|
||||
LOOP_REMOTE_REVIEW=""
|
||||
LOOP_WAIT_OPEN_JOBS=0
|
||||
LOOP_JOB_TIMEOUT=""
|
||||
|
||||
# Print usage instructions
|
||||
usage() {
|
||||
@@ -53,6 +54,7 @@ usage() {
|
||||
echo " --all-reviewer Enforce PASS verdict from all active reviewer sessions"
|
||||
echo " --max-loop N Max execution-review corrective loop runs (default: 3)"
|
||||
echo " --max-rebut N Max rebuttal attempts per review iteration (default: 1, 0: disabled)"
|
||||
echo " --job-timeout <sec> Budget of each delegated job (default: \$MAM_JOB_TIMEOUT_S or 3600)"
|
||||
echo " --verbose Print detailed execution timeline traces"
|
||||
echo " --cleanup Purge temporary job directories upon success"
|
||||
echo " --worktree <path> Source worktree for diff/base/head (control plane stays here)"
|
||||
@@ -104,6 +106,7 @@ while [[ "$#" -gt 0 ]]; do
|
||||
--review-isolation) LOOP_REVIEW_ISOLATION="$2"; shift 2 ;;
|
||||
--remote-review) LOOP_REMOTE_REVIEW="$2"; shift 2 ;;
|
||||
--wait-open-jobs) LOOP_WAIT_OPEN_JOBS=1; shift ;;
|
||||
--job-timeout) LOOP_JOB_TIMEOUT="${2:-}"; shift 2 ;;
|
||||
-h|--help) usage ;;
|
||||
*) echo "Unknown option: $1"; usage ;;
|
||||
esac
|
||||
@@ -133,8 +136,8 @@ fi
|
||||
if [ "${MAM_LOOP_PY:-1}" = "0" ] && { [ -n "$LOOP_WORKTREE" ] || [ -n "$LOOP_BASE" ] \
|
||||
|| [ "$LOOP_REVIEW_ONLY" = "1" ] || [ -n "${MAM_LOOP_WORKTREE:-}" ] \
|
||||
|| [ -n "$LOOP_REVIEW_ISOLATION" ] || [ -n "$LOOP_REMOTE_REVIEW" ] \
|
||||
|| [ -n "$LOOP_PLAN_FILE" ] || [ "$LOOP_WAIT_OPEN_JOBS" = "1" ]; }; then
|
||||
echo "ERROR: --worktree/--base/--review-only/--review-isolation/--remote-review/--plan-file/--wait-open-jobs require the Python loop (MAM_LOOP_PY=1)" >&2
|
||||
|| [ -n "$LOOP_PLAN_FILE" ] || [ "$LOOP_WAIT_OPEN_JOBS" = "1" ] || [ -n "$LOOP_JOB_TIMEOUT" ]; }; then
|
||||
echo "ERROR: --worktree/--base/--review-only/--review-isolation/--remote-review/--plan-file/--wait-open-jobs/--job-timeout require the Python loop (MAM_LOOP_PY=1)" >&2
|
||||
exit 1
|
||||
fi
|
||||
|
||||
|
||||
+1
-1
@@ -11,7 +11,7 @@ positional arguments:
|
||||
get print one job record as JSON
|
||||
status set a job status
|
||||
update update a job record
|
||||
close close a job with deadline_timeout or cancelled
|
||||
close close a job with deadline_timeout, wall_clock_timeout or cancelled
|
||||
get-feedback get the last feedback detail (completed/error) for a
|
||||
job
|
||||
pick claim a pending job for a session; prints id
|
||||
|
||||
@@ -1286,7 +1286,9 @@ def test_loop_runner_passes_the_contract_and_remote_label(tmp_path, monkeypatch)
|
||||
r.parse_args()
|
||||
assert r.session_label("creator-claude-01") == "herdr:creator-claude-01"
|
||||
assert r.session_label("reviewer-far-01") == "remote:reviewer-far-01"
|
||||
assert r.contract_args() == ["--heartbeat", "20", "--heartbeat-misses", "3", "--ack-timeout", "45"]
|
||||
# Issue #33: the job budget is always passed explicitly (default 3600)
|
||||
assert r.contract_args() == ["--timeout", "3600", "--heartbeat", "20", "--heartbeat-misses", "3",
|
||||
"--ack-timeout", "45"]
|
||||
seen = []
|
||||
|
||||
def fake_run(cmd, **_kw):
|
||||
|
||||
@@ -0,0 +1,324 @@
|
||||
"""Issue #33: the job budget travels, the wait caps follow it, and the two
|
||||
clocks that close a job carry different labels.
|
||||
|
||||
- B1: the real wrapper takes the budget from --timeout > $MAM_JOB_TIMEOUT_S > 3600.
|
||||
- B2: the loop runner derives its wait caps from the budget (+300 s) and hands
|
||||
the wrapper that budget explicitly; both hops run for real.
|
||||
- B3: the real wrapper + subscriber label a spent budget `wall_clock_timeout`
|
||||
(subscriber rc 4) and silence `deadline_timeout` (rc 2); caller rc is 2 for
|
||||
both. These need the live broker from the environment (like test_issue6 t1_1).
|
||||
- B4: the remote runner's two deadline wordings lead with the new label.
|
||||
- B5: the sub-job table files `wall_clock_timeout` closes as unconfirmed.
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import json
|
||||
import os
|
||||
import re
|
||||
import signal
|
||||
import subprocess
|
||||
import sys
|
||||
import time
|
||||
import uuid
|
||||
from pathlib import Path
|
||||
|
||||
import pytest
|
||||
|
||||
REPO_ROOT = Path(__file__).resolve().parent.parent
|
||||
SKILLS = REPO_ROOT / ".agents" / "skills"
|
||||
WRAPPER = SKILLS / "multi-agent-mux-delegate-job" / "multi-agent-mux-delegate-job"
|
||||
REGISTRY = SKILLS / "multi-agent-mux-delegate-job" / "scripts" / "registry.py"
|
||||
PUBLISH = SKILLS / "multi-agent-mux-delegate-job" / "scripts" / "publish_event.py"
|
||||
|
||||
if str(SKILLS) not in sys.path:
|
||||
sys.path.insert(0, str(SKILLS))
|
||||
|
||||
UNREACHABLE = {"MQTT_BROKER": "127.0.0.1", "MQTT_PORT": "9", "MQTT_TLS": "0"}
|
||||
|
||||
|
||||
def _env(home: Path, extra=None, broker: bool = False) -> dict:
|
||||
env = dict(os.environ)
|
||||
env["DELEGATE_JOB_PYTHON"] = sys.executable
|
||||
env["AGENT_PYTHON_BIN"] = sys.executable
|
||||
env["HOME"] = str(home)
|
||||
env["WORKSPACE_ROOT"] = str(home)
|
||||
env["PYTHONPATH"] = str(SKILLS)
|
||||
env["DELEGATE_JOB_LOGS_DIR"] = str(home / "logs")
|
||||
for k in ("MAM_JOBS_DIR", "MAM_REAL_ROOT", "MAM_JOB_ID", "MAM_JOB_TIMEOUT_S", "MAM_CHILD_WAIT_S",
|
||||
"MAM_WAIT_GRACE_S"):
|
||||
env.pop(k, None)
|
||||
if not broker:
|
||||
env["MAM_ENV_FILE"] = str(home / ".mam.env.absent")
|
||||
for k in ("MQTT_BROKER", "MQTT_HOST", "MQTT_PORT", "MQTT_TLS", "MQTT_USERNAME", "MQTT_PASSWORD"):
|
||||
env.pop(k, None)
|
||||
env.update(UNREACHABLE)
|
||||
if extra:
|
||||
env.update({k: str(v) for k, v in extra.items()})
|
||||
return env
|
||||
|
||||
|
||||
def _dry_submit(env: dict, reg: Path, *extra: str) -> subprocess.CompletedProcess:
|
||||
return subprocess.run(["bash", str(WRAPPER), "submit", "--agent", "human", "--dry-run",
|
||||
"--registry-dir", str(reg), "--prompt", "p", *extra],
|
||||
capture_output=True, text=True, env=env, cwd=env["HOME"], timeout=120)
|
||||
|
||||
|
||||
def _jid(res: subprocess.CompletedProcess) -> str:
|
||||
assert res.returncode == 0, res.stdout + res.stderr
|
||||
m = re.search(r"registered job:\s*(\S+)", res.stdout)
|
||||
assert m, res.stdout
|
||||
return m.group(1)
|
||||
|
||||
|
||||
def _record(reg: Path, jid: str) -> dict:
|
||||
return json.loads((reg / f"{jid}.json").read_text(encoding="utf-8"))
|
||||
|
||||
|
||||
def _events(reg: Path, jid: str) -> list:
|
||||
p = reg / f"{jid}.events.log"
|
||||
return [json.loads(l) for l in p.read_text().splitlines() if l.strip()] if p.exists() else []
|
||||
|
||||
|
||||
def _publish(env: dict, reg: Path, jid: str, event: str, *extra: str) -> subprocess.CompletedProcess:
|
||||
tok = _record(reg, jid)["dispatch_token"]
|
||||
res = subprocess.run([sys.executable, str(PUBLISH), "--registry-dir", str(reg), "--job", jid,
|
||||
"--event", event, "--expect-dispatch-token", tok, *extra],
|
||||
capture_output=True, text=True, env=env, timeout=120)
|
||||
assert res.returncode in (0, 2), res.stderr
|
||||
return res
|
||||
|
||||
|
||||
def _kill_timer(reg: Path, jid: str) -> None:
|
||||
try:
|
||||
os.kill(int((reg / f"{jid}.heartbeat.pid").read_text().strip()), signal.SIGKILL)
|
||||
except (OSError, ValueError):
|
||||
pass
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# B1 - the wrapper's budget: --timeout > MAM_JOB_TIMEOUT_S > 3600
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
@pytest.mark.parametrize("env_val,flag,expected,warns", [
|
||||
(None, None, 3600, False),
|
||||
("7", None, 7, False),
|
||||
("7", "9", 9, False),
|
||||
("abc", None, 3600, True),
|
||||
])
|
||||
def test_b1_the_wrapper_takes_the_budget_from_flag_env_or_default(tmp_path, env_val, flag, expected, warns):
|
||||
env = _env(tmp_path, {"MAM_JOB_TIMEOUT_S": env_val} if env_val else None)
|
||||
res = _dry_submit(env, tmp_path / "reg", *(["--timeout", flag] if flag else []))
|
||||
assert _record(tmp_path / "reg", _jid(res))["timeout_sec"] == expected
|
||||
assert ("MAM_JOB_TIMEOUT_S=abc ignored" in res.stderr) is warns, res.stderr
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# B2 - the runner: budget -> wait caps, and the budget handed to the wrapper
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
def _runner(tmp_path, monkeypatch, *argv, **env):
|
||||
monkeypatch.setenv("WORKSPACE_ROOT", str(tmp_path))
|
||||
monkeypatch.setenv("MAM_JOBS_DIR", str(tmp_path / "reg"))
|
||||
monkeypatch.setenv("DELEGATE_JOB_LOGS_DIR", str(tmp_path / "logs"))
|
||||
for k in ("MAM_REAL_ROOT", "MAM_JOB_TIMEOUT_S", "MAM_CHILD_WAIT_S", "MAM_WAIT_GRACE_S", "MAM_JOB_TREE_MAX"):
|
||||
monkeypatch.delenv(k, raising=False)
|
||||
for k, v in env.items():
|
||||
monkeypatch.setenv(k, str(v))
|
||||
from lib_py.loop import runner as lr
|
||||
r = lr.LoopRunner(["--creator", "c", "--task", "t", *argv])
|
||||
r.parse_args()
|
||||
return r
|
||||
|
||||
|
||||
def test_b2_the_wait_caps_are_the_budget_plus_300(tmp_path, monkeypatch):
|
||||
assert _runner(tmp_path, monkeypatch, "--job-timeout", "10").job_wait_s == 310
|
||||
assert _runner(tmp_path, monkeypatch, MAM_JOB_TIMEOUT_S=20).job_wait_s == 320
|
||||
assert _runner(tmp_path, monkeypatch, "--job-timeout", "10", MAM_JOB_TIMEOUT_S=20).job_wait_s == 310
|
||||
r = _runner(tmp_path, monkeypatch)
|
||||
assert (r.job_budget, r.job_wait_s) == (3600, 3900) # no option: today's numbers
|
||||
assert "--job-timeout" in "\n".join(_usage_lines(r))
|
||||
|
||||
|
||||
def _usage_lines(r):
|
||||
import io, contextlib
|
||||
buf = io.StringIO()
|
||||
with contextlib.redirect_stdout(buf), contextlib.redirect_stderr(buf):
|
||||
try:
|
||||
r.print_usage()
|
||||
except SystemExit:
|
||||
pass
|
||||
return buf.getvalue().splitlines()
|
||||
|
||||
|
||||
def test_b2_an_invalid_job_timeout_is_refused(tmp_path, monkeypatch):
|
||||
with pytest.raises(SystemExit):
|
||||
_runner(tmp_path, monkeypatch, "--job-timeout", "0")
|
||||
|
||||
|
||||
def test_b2_the_child_wait_defaults_to_the_budget_and_an_explicit_value_wins(tmp_path, monkeypatch, capsys):
|
||||
env = _env(tmp_path)
|
||||
reg = tmp_path / "reg"
|
||||
p = _jid(_dry_submit(env, reg))
|
||||
_jid(_dry_submit(env, reg, "--parent-job", p))
|
||||
|
||||
start = time.time()
|
||||
r = _runner(tmp_path, monkeypatch, "--job-timeout", "1", MAM_WAIT_GRACE_S=1)
|
||||
assert r.wait_for_descendants(p, interval=0.5) is False
|
||||
assert 2 <= time.time() - start < 8
|
||||
assert "ended after 2s (MAM_CHILD_WAIT_S default: job budget 1 + 1)" in capsys.readouterr().out
|
||||
|
||||
start = time.time()
|
||||
r = _runner(tmp_path, monkeypatch, "--job-timeout", "600", MAM_CHILD_WAIT_S=2)
|
||||
assert r.wait_for_descendants(p, interval=0.5) is False
|
||||
assert 2 <= time.time() - start < 8
|
||||
assert "ended after 2s (MAM_CHILD_WAIT_S)" in capsys.readouterr().out
|
||||
|
||||
|
||||
def test_b2_the_runner_hands_the_wrapper_its_budget_and_the_wrapper_registers_it(tmp_path, monkeypatch):
|
||||
# hop 1: the runner execs the wrapper with --timeout (a recording wrapper at the control root)
|
||||
rec = tmp_path / "rec.args"
|
||||
w = tmp_path / ".agents" / "skills" / "multi-agent-mux-delegate-job" / "multi-agent-mux-delegate-job"
|
||||
w.parent.mkdir(parents=True)
|
||||
w.write_text(f'#!/usr/bin/env bash\nprintf "%s\\n" "$@" > "{rec}"\necho "registered job: fake33"\n')
|
||||
w.chmod(0o755)
|
||||
r = _runner(tmp_path, monkeypatch, "--job-timeout", "10")
|
||||
assert r.delegate_job("c", "claude", "Worker", "task") == "fake33"
|
||||
args = rec.read_text().splitlines()
|
||||
assert args[args.index("--timeout") + 1] == "10"
|
||||
# env only: still passed explicitly
|
||||
r = _runner(tmp_path, monkeypatch, MAM_JOB_TIMEOUT_S=20)
|
||||
assert r.contract_args()[:2] == ["--timeout", "20"]
|
||||
|
||||
# hop 2: the real wrapper registers what the runner hands it
|
||||
reg = tmp_path / "reg2"
|
||||
res = _dry_submit(_env(tmp_path), reg, *_runner(tmp_path, monkeypatch, "--job-timeout", "10").contract_args())
|
||||
assert _record(reg, _jid(res))["timeout_sec"] == 10
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# B3 - the real wrapper + subscriber: which clock closed the job
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
def _run_wrapper_bg(env: dict, reg: Path, *extra: str) -> subprocess.Popen:
|
||||
return subprocess.Popen(["bash", str(WRAPPER), "submit", "--agent", "human", "--registry-dir", str(reg),
|
||||
"--workdir", env["HOME"], "--prompt", "b3", *extra],
|
||||
stdout=subprocess.PIPE, stderr=subprocess.PIPE, text=True, env=env, cwd=env["HOME"])
|
||||
|
||||
|
||||
def _wait_subscribed(reg: Path, timeout: float = 30) -> str:
|
||||
deadline = time.time() + timeout
|
||||
while time.time() < deadline:
|
||||
for f in reg.glob("*.subscriber.out"):
|
||||
if "SUBSCRIBED" in f.read_text(errors="replace"):
|
||||
return f.name.split(".")[0]
|
||||
time.sleep(0.1)
|
||||
raise AssertionError("the subscriber never subscribed (is the broker up?)")
|
||||
|
||||
|
||||
def _last_error(reg: Path, jid: str) -> str:
|
||||
errs = [e for e in _events(reg, jid) if e.get("event") == "error"]
|
||||
assert errs, _events(reg, jid)
|
||||
return errs[-1].get("detail", "")
|
||||
|
||||
|
||||
def test_b3_wall_clock_before_idle_is_labelled_wall_clock_timeout(tmp_path):
|
||||
env = _env(tmp_path, broker=True)
|
||||
reg = tmp_path / "jobs"
|
||||
proc = _run_wrapper_bg(env, reg, "--timeout", "3", "--idle-timeout", "30")
|
||||
out, err = proc.communicate(timeout=90)
|
||||
assert proc.returncode == 2, out + err
|
||||
jid = next(reg.glob("*.json")).stem
|
||||
assert _record(reg, jid)["status"] == "error"
|
||||
assert _last_error(reg, jid) == "wall_clock_timeout"
|
||||
assert "wall-clock timeout" in (reg / f"{jid}.subscriber.out").read_text()
|
||||
assert "closed by wall_clock clock" in err
|
||||
|
||||
|
||||
def test_b3_silence_is_still_labelled_deadline_timeout(tmp_path):
|
||||
env = _env(tmp_path, broker=True)
|
||||
reg = tmp_path / "jobs"
|
||||
proc = _run_wrapper_bg(env, reg, "--timeout", "30", "--idle-timeout", "2")
|
||||
try:
|
||||
jid = _wait_subscribed(reg)
|
||||
_publish(env, reg, jid, "started") # then nothing: silence for K x N
|
||||
out, err = proc.communicate(timeout=90)
|
||||
finally:
|
||||
proc.kill()
|
||||
assert proc.returncode == 2, out + err
|
||||
assert _record(reg, jid)["status"] == "error"
|
||||
assert _last_error(reg, jid) == "deadline_timeout"
|
||||
assert "idle timeout" in (reg / f"{jid}.subscriber.out").read_text()
|
||||
assert "closed by no_event clock" in err
|
||||
|
||||
|
||||
def test_b3_a_heartbeating_job_that_spends_its_budget_is_wall_clock_timeout(tmp_path):
|
||||
"""The #33 motivating case: a live agent (heartbeats keep coming) whose
|
||||
work outlasts the budget was reported as `deadline_timeout`."""
|
||||
env = _env(tmp_path, broker=True)
|
||||
reg = tmp_path / "jobs"
|
||||
proc = _run_wrapper_bg(env, reg, "--timeout", "6", "--idle-timeout", "3")
|
||||
jid = None
|
||||
try:
|
||||
jid = _wait_subscribed(reg)
|
||||
_publish(env, reg, jid, "started", "--heartbeat", "1")
|
||||
out, err = proc.communicate(timeout=90)
|
||||
finally:
|
||||
proc.kill()
|
||||
if jid:
|
||||
_kill_timer(reg, jid)
|
||||
assert proc.returncode == 2, out + err
|
||||
assert _last_error(reg, jid) == "wall_clock_timeout"
|
||||
assert "wall-clock timeout" in (reg / f"{jid}.subscriber.out").read_text()
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# B4 - the remote runner's deadlines are wall clocks
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
def _dispatch(timeout_sec=1) -> dict:
|
||||
return {"job_id": uuid.uuid4().hex[:8], "brief": "b", "dispatch_token": "tok-" + uuid.uuid4().hex,
|
||||
"attempt_id": 1, "auth_token": None, "timeout_sec": timeout_sec, "heartbeat_sec": 30,
|
||||
"heartbeat_misses": 4, "ack_timeout_sec": 5}
|
||||
|
||||
|
||||
@pytest.mark.parametrize("cmd,prefix", [("sleep 5", "wall_clock_timeout: agent command exceeded timeout_sec 1"),
|
||||
(None, "wall_clock_timeout (remote runner)")])
|
||||
def test_b4_the_remote_runner_labels_its_deadline_wall_clock_timeout(tmp_path, monkeypatch, cmd, prefix):
|
||||
from lib_py.delegation import remote
|
||||
for k, v in _env(tmp_path).items():
|
||||
monkeypatch.setenv(k, v)
|
||||
monkeypatch.chdir(tmp_path)
|
||||
reg = tmp_path / "jobs"
|
||||
d = _dispatch()
|
||||
try:
|
||||
remote.handle_dispatch(d, str(reg), "s", cmd)
|
||||
assert _record(reg, d["job_id"])["status"] == "error"
|
||||
assert _last_error(reg, d["job_id"]).startswith(prefix)
|
||||
finally:
|
||||
_kill_timer(reg, d["job_id"])
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# B5 - the sub-job table: a wall-clock close is unconfirmed, like a deadline close
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
@pytest.mark.parametrize("request_kind,detail", [
|
||||
("wall_clock_timeout", "wall_clock_timeout"),
|
||||
("wall_clock_timeout", "wall_clock_timeout: agent command exceeded timeout_sec 1"),
|
||||
("deadline_timeout", "deadline_timeout"),
|
||||
])
|
||||
def test_b5_a_wall_clock_close_is_closed_unconfirmed(tmp_path, monkeypatch, request_kind, detail):
|
||||
env = _env(tmp_path)
|
||||
reg = tmp_path / "reg"
|
||||
p = _jid(_dry_submit(env, reg))
|
||||
c = _jid(_dry_submit(env, reg, "--parent-job", p))
|
||||
tok = _record(reg, c)["dispatch_token"]
|
||||
res = subprocess.run([sys.executable, str(REGISTRY), "--registry-dir", str(reg), "close", "--job", c,
|
||||
"--request", request_kind, "--expect-dispatch-token", tok],
|
||||
capture_output=True, text=True, env=env, timeout=120)
|
||||
assert res.returncode == 0, res.stderr
|
||||
assert _record(reg, c)["status"] == "error"
|
||||
_publish(env, reg, c, "error", "--detail", detail)
|
||||
block = _runner(tmp_path, monkeypatch)._subjobs_block([p])
|
||||
assert f"| CLOSED-UNCONFIRMED | {detail} |" in block, block
|
||||
@@ -359,7 +359,7 @@ def test_job_subscriber_cli_contract_snapshot(mam_sandbox):
|
||||
assert job_subscriber.TERMINAL_EVENTS == ("completed", "error")
|
||||
src = Path(job_subscriber.__file__).read_text(encoding="utf-8")
|
||||
for doc in (" 0 all watched jobs reached", " 1 any watched job reached",
|
||||
" 2 timed out"):
|
||||
" 2 no event for the idle window", " 4 the wall-clock budget"):
|
||||
assert doc in src, doc
|
||||
assert 'return 3' in src, "fatal-error exit code 3 must survive"
|
||||
|
||||
|
||||
Reference in new issue
Block a user