fix(issue-23): onboarding delivery is judged by the agent's own started event, and a rollback verifies the kill

Plan commits 3 and 4 landed together: both rewrite the same region of
create_session.sh and share one test file, and splitting them afterwards would
have meant hunk-level surgery on already-verified code.

Delivery verdict (item 3). create_session --onboard called a healthy agent a
failure three seconds after registering the job: inject_instructions ->
send_keys_safe returns rc 4 when `agent prompt --wait --until working` fails
and the pane is still not working two seconds later, which is exactly where a
TUI that is still starting up lands. It never got the ISSUE-18 confirmation the
delegate-job wrapper has. rc 4 is a warning now and the agent's own `started`
decides, within the job's own ack timeout; rc 1/2/3 stay hard failures, since
they say the pane never quiesced, a dialog was blocking, or the text never
appeared, and no later `started` repairs those.

The self-published `started` had to go first. create_session published it on
the agent's behalf right after injection, so the registry showed a started job
whether or not the agent ever saw the prompt - with that line in place, no
started-based verdict can mean anything.

delegate_wait_started is lib.sh's counterpart to the wrapper's _wait_started
(plan item D10-b). The wrapper's own `submit` was the first choice, but it
blocks until the job reaches a terminal state, and create_session must return
as soon as delivery is confirmed; the on-disk evidence it reads - registry
status past `pending`, or a started line carrying this dispatch token - is
written by publish_event before its wire publish, so no broker is involved.

Rollback integrity (item 4). The trap ran `_herdr kill-session -t
"$SESSION_NAME" 2>/dev/null || true`, so a kill that closed nothing still
printed "rolling back" while the session kept running, and the row stayed
`running` pointing at the job the same rollback had just failed (#23 symptom
5). With item 1 in place this check is finally trustworthy: the kill used to
fail because the caller's workspace id hid the pane.

The trap now reads the kill's rc, confirms with has-session, closes the
onboarding job as `cancelled` (a terminal transition the registry knows, and
the truthful one - the job was never dispatched), and marks the row. A session
still alive exits 43 with the manual cleanup command, distinct from 42 (TUI
never ready).

The row keeps a schema-valid status rather than the plan's `error`, which
atomic_yaml.py rejects: `terminated` once the session is really gone, and
`running` when the kill failed, because it is still running. What makes that
case legible is the note, the cleared delegate_job_id and exit 43 - not a
status claiming the opposite of the truth. The row is never deleted; a deleted
row takes the evidence with it.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
GodopuandClaude Opus 5 committed 2026-09-22 04:28:27 +00:00
1 parent 5ba04a27ca
commit 123dca47bb
3 files changed
+345 -6

No files matched your search

+49
View File
@@ -2131,6 +2131,55 @@ delegate_publish_event() {
_delegation_py publish --job "$job_id" --event "$event" --detail "$detail" ${extra[@]+"${extra[@]}"} || true
}
# delegate_wait_started <job_id> [ack_timeout_s] [dispatch_token]
#
# ISSUE-23 / ISSUE-18: delivery is confirmed by the protocol, not by the
# screen. `agent prompt --wait --until working` failing two seconds after the
# keys were handed over says nothing about a TUI that is still starting up -
# that is exactly what made create_session --onboard call a healthy agent a
# failure. The evidence is the agent's own `started`: the registry record
# leaves `pending` (publish_event syncs it on this host) or a matching started
# line lands in the job's events.log, which publish_event writes before its
# wire publish so a slow broker cannot delay the verdict.
#
# Returns 0 on that evidence, 1 if neither appeared within T. Never re-injects:
# the single-injection contract is fail-closed.
delegate_wait_started() {
local job_id="$1" ack_s="${2:-180}" tok="${3:-}"
[ -n "$job_id" ] || return 1
local reg_dir="${MAM_JOBS_DIR:-${WORKSPACE_ROOT:-$PWD}/.mam/jobs}"
local rec="$reg_dir/$job_id.json"
local ev_log="$reg_dir/$job_id.events.log"
local started_re='"event": *"started"'
if [ -n "$tok" ]; then
started_re='"event": *"started".*"dispatch_token": *"'"$tok"'"'
fi
local deadline st
deadline=$(( $(date +%s) + ack_s ))
while :; do
st=""
if [ -f "$rec" ]; then
st=$(REC="$rec" python3 -c "
import json, os
try:
print(json.load(open(os.environ['REC'])).get('status', '') or '')
except Exception:
print('')
" 2>/dev/null || true)
fi
if [ -n "$st" ] && [ "$st" != "pending" ]; then
return 0
fi
if [ -f "$ev_log" ] && grep -Eq "$started_re" "$ev_log" 2>/dev/null; then
return 0
fi
if [ "$(date +%s)" -ge "$deadline" ]; then
return 1
fi
sleep 1
done
}
# ensure_subscriber_daemon <job_id> [workdir]
# Start the monitor subscriber for this workspace unless one is already running.
# Prints the PID(s) on stdout, exactly as start_watchdog always did.
@@ -283,13 +283,63 @@ NOW_ISO=$(date -u +'%Y-%m-%dT%H:%M:%SZ')
spawn
# _mark_row_rolled_back <status> <note>
# ISSUE-23: the YAML row and the job registration are both written before the
# prompt is injected, so a rollback that only kills the pane leaves a row that
# says `running` pointing at a failed job - which is what status.sh keeps
# reporting (symptom 5). Mark the row instead of deleting it: a deleted row
# takes the evidence with it.
#
# <status> stays inside the schema's vocabulary (running/terminated/archived/
# stopped - atomic_yaml.py rejects anything else): `terminated` when the
# session is really gone, and `running` when the kill failed, because it IS
# still running and saying otherwise would be the same lie in reverse. What
# makes the failed case legible is the note, the cleared job id and exit 43.
_mark_row_rolled_back() {
local status="$1" note="$2"
[ "${ROW_APPENDED:-0}" = "1" ] || return 0
atomic_dump_yaml "$AGENT_SESSIONS_YAML" \
SESSION_NAME="$SESSION_NAME" ROLLBACK_STATUS="$status" ROLLBACK_NOTE="$note" <<'PYEOF' || true
name = os.environ['SESSION_NAME']
status = os.environ['ROLLBACK_STATUS']
note = os.environ['ROLLBACK_NOTE']
for s in d.get('herdr_sessions', []):
if s.get('name') == name:
s['status'] = status
s['last_visible_status'] = note
s['delegate_job_id'] = None
break
PYEOF
}
# Trap for rolling back/cleaning up herdr session if script exits due to error
cleanup_herdr_on_error() {
local exit_code=$?
if [ $exit_code -ne 0 ]; then
echo "⚠️ Error occurred during initialization (exit code $exit_code). Rolling back and killing herdr session '$SESSION_NAME'..." >&2
_herdr kill-session -t "$SESSION_NAME" 2>/dev/null || true
[ $exit_code -eq 0 ] && return 0
echo "⚠️ Error occurred during initialization (exit code $exit_code). Rolling back and killing herdr session '$SESSION_NAME'..." >&2
# ISSUE-23: the kill result used to be discarded (`2>/dev/null || true`), so
# a kill that closed nothing still printed "rolled back" while the session
# kept running. Check it, then confirm with has-session.
local kill_rc=0
_herdr kill-session -t "$SESSION_NAME" || kill_rc=$?
local alive=0
_herdr has-session -t "$SESSION_NAME" >/dev/null 2>&1 && alive=1
# Release the onboarding job: `cancelled` is a terminal transition the
# registry knows, and it says what happened - the job was never really
# dispatched. Best effort; a failure here must not stop the rollback.
if [ -n "${DELEGATE_JOB_ID:-}" ]; then
delegate_publish_event "$DELEGATE_JOB_ID" cancelled "rolled back by create_session" "${DELEGATE_JOB_TOKEN:-}" "${DELEGATE_JOB_ATTEMPT:-}" || true
fi
if [ "$alive" = "1" ]; then
_mark_row_rolled_back "running" "rollback-failed"
echo "ERROR: rollback could not kill herdr session '$SESSION_NAME' (kill rc=$kill_rc) - it is still running." >&2
echo " Clean it up with: HERDR_SESSION_NAME=${HERDR_SESSION_NAME:-default} herdr kill-session -t $SESSION_NAME" >&2
exit 43
fi
_mark_row_rolled_back "terminated" "rolled-back"
}
trap cleanup_herdr_on_error EXIT
@@ -390,6 +440,7 @@ if [ -n "$SUBMIT_JOB_PROMPT" ]; then
echo "Submitted delegated job: $DELEGATE_JOB_ID"
DELEGATE_JOB_TOKEN=""
DELEGATE_JOB_ATTEMPT=""
DELEGATE_JOB_ACK_S=""
if [ -n "$DELEGATE_JOB_ID" ]; then
local_info=$(python3 -c "
import sys, json, os
@@ -402,13 +453,15 @@ if os.path.exists(p):
d = json.load(f)
tok = d.get('dispatch_token', '')
att = d.get('attempt_id', d.get('iteration', 1))
print(f'{tok} {att}')
ack = d.get('ack_timeout_sec', 180)
print(f'{tok} {att} {ack}')
except Exception:
pass
" 2>/dev/null || true)
if [ -n "$local_info" ]; then
DELEGATE_JOB_TOKEN=$(echo "$local_info" | awk '{print $1}')
DELEGATE_JOB_ATTEMPT=$(echo "$local_info" | awk '{print $2}')
DELEGATE_JOB_ACK_S=$(echo "$local_info" | awk '{print $3}')
fi
fi
fi
@@ -547,6 +600,7 @@ snap['taken_at'] = os.environ['NOW_ISO']
snap['cwd'] = os.environ['PANE_CWD']
print(f"appended: {name}", flush=True)
PYEOF
ROW_APPENDED=1
echo
echo "=== created ==="
@@ -582,12 +636,27 @@ Task: $SUBMIT_JOB_PROMPT"
# Inject instructions into the herdr pane
rc=0
inject_instructions "$SESSION_NAME" "$instructions" "$DELEGATE_JOB_ID" || rc=$?
if [ "$rc" -ne 0 ]; then
# ISSUE-23: rc 4 is "Enter was not seen to be accepted within the send_keys
# window", which is where a TUI that is still finishing its start-up lands.
# It is a warning now; the agent's own `started` decides. rc 1/2/3 are still
# failures: they say the pane never quiesced, a dialog was blocking, or the
# text never appeared - none of which a later `started` can repair.
if [ "$rc" -ne 0 ] && [ "$rc" -ne 4 ]; then
delegate_publish_event "$DELEGATE_JOB_ID" error "instruction injection failed (prompt-lock, rc=$rc)" "$DELEGATE_JOB_TOKEN" "$DELEGATE_JOB_ATTEMPT"
exit 1
fi
if [ "$rc" -eq 4 ]; then
echo "WARNING: Enter was not observed to be accepted for '$SESSION_NAME' (rc=4); waiting for the agent's own started event instead." >&2
fi
delegate_publish_event "$DELEGATE_JOB_ID" started "multi-agent-mux session created and instructions injected" "$DELEGATE_JOB_TOKEN" "$DELEGATE_JOB_ATTEMPT"
# ISSUE-23: this script no longer publishes `started` on the agent's behalf.
# It used to, which made the registry show a started job even when the agent
# never saw the prompt, and left any started-based verdict meaningless.
if ! delegate_wait_started "$DELEGATE_JOB_ID" "${DELEGATE_JOB_ACK_S:-180}" "$DELEGATE_JOB_TOKEN"; then
delegate_publish_event "$DELEGATE_JOB_ID" error "onboarding delivery unconfirmed: no started within ${DELEGATE_JOB_ACK_S:-180}s" "$DELEGATE_JOB_TOKEN" "$DELEGATE_JOB_ATTEMPT"
echo "ERROR: '$SESSION_NAME' did not acknowledge the onboarding prompt within ${DELEGATE_JOB_ACK_S:-180}s" >&2
exit 1
fi
# Trigger immediate priority reconcile cycle asynchronously
# Issue #21 phase 2 (A8): the control root's reconcile/watchdog, never the
# (unreviewed) copy in a worktree --workspace; identical paths by default.
+221
View File
@@ -444,3 +444,224 @@ def test_s6b_create_session_no_longer_gates_dialogs_on_claude(mam_sandbox):
assert call, "create_session no longer answers start-up dialogs at all"
assert all('"$AGENT"' in l for l in call), call
assert 'if [ "$AGENT" = "claude" ] && [ -z "$LAST_VISIBLE_STATUS_OVERRIDE" ]' not in src
# --------------------------------------------------------------------------
# item 3 — onboarding delivery is judged by the agent's own `started` (#23)
# --------------------------------------------------------------------------
def _create_sh(tmp_path):
return tmp_path / ".agents" / "skills" / "multi-agent-mux-create" / "scripts" / "create_session.sh"
def _extract(path, start_marker, end_marker, close=None):
"""Lift a block out of create_session.sh so the test runs the shipped code
rather than a paraphrase of it. A moved marker fails loudly here.
`close` closes the construct the end marker opens: the block runs to the
first line equal to it after the end marker (e.g. the `fi` of an `if`)."""
lines = open(path).read().splitlines(True)
start = next((i for i, l in enumerate(lines) if start_marker in l), None)
assert start is not None, "start marker %r is gone from %s" % (start_marker, path)
end = next((i for i, l in enumerate(lines[start:], start) if end_marker in l), None)
assert end is not None, "end marker %r is gone from %s" % (end_marker, path)
if close is not None:
end = next((i for i, l in enumerate(lines[end:], end) if l.strip() == close), None)
assert end is not None, "block opened at %r is never closed with %r" % (end_marker, close)
return "".join(lines[start:end + 1])
def _seed_job(tmp_path, job_id, status="pending", started_token=None):
jobs = tmp_path / ".mam" / "jobs"
jobs.mkdir(parents=True, exist_ok=True)
(jobs / ("%s.json" % job_id)).write_text(json.dumps(
{"job_id": job_id, "status": status, "dispatch_token": "tok-1",
"attempt_id": 1, "ack_timeout_sec": 2}))
ev = jobs / ("%s.events.log" % job_id)
if started_token is None:
if ev.exists():
ev.unlink()
else:
ev.write_text(json.dumps(
{"job": job_id, "event": "started", "dispatch_token": started_token}) + "\n")
return jobs
def _run_delivery(tmp_path, inject_rc, job_id="job1", **seed):
"""Run create_session.sh's own delivery block with a stubbed injection."""
lib = tmp_path / ".agents" / "skills" / "lib.sh"
block = _extract(_create_sh(tmp_path), "# Inject instructions into the herdr pane",
"delegate_wait_started", close="fi")
_seed_job(tmp_path, job_id, **seed)
pub_log = tmp_path / "published.txt"
script = '''
set -euo pipefail
source "%s"
SESSION_NAME=test-sess
DELEGATE_JOB_ID=%s
DELEGATE_JOB_TOKEN=tok-1
DELEGATE_JOB_ATTEMPT=1
DELEGATE_JOB_ACK_S=2
instructions="hello"
inject_instructions() { return %d; }
delegate_publish_event() { printf '%%s\\n' "$2" >> "%s"; }
%s
echo DELIVERED
''' % (lib, job_id, inject_rc, pub_log, block)
env = dict(os.environ, MAM_JOBS_DIR=str(tmp_path / ".mam" / "jobs"))
res = subprocess.run(["bash", "-c", script], capture_output=True, text=True,
cwd=str(tmp_path), env=env)
published = pub_log.read_text().split() if pub_log.exists() else []
return res, published
def test_s7_create_session_no_longer_publishes_started_for_the_agent(mam_sandbox):
"""S7 (source): create_session used to publish `started` itself, so the
registry showed a started job even when the agent never saw the prompt.
With that line present no started-based verdict can mean anything."""
src = open(_create_sh(mam_sandbox)).read()
assert 'delegate_publish_event "$DELEGATE_JOB_ID" started' not in src
assert "delegate_wait_started" in src
def test_s7b_delivery_succeeds_on_the_agents_own_started(mam_sandbox):
"""S7b (real registry files, stubbed injection): a started line carrying
this dispatch token is the evidence."""
res, published = _run_delivery(mam_sandbox, 0, started_token="tok-1")
assert "DELIVERED" in res.stdout, res.stdout + res.stderr
assert published == [], published
def test_s7c_delivery_succeeds_when_the_registry_left_pending(mam_sandbox):
"""S7c: publish_event syncs the record on this host, so a status past
`pending` is the same evidence."""
res, _ = _run_delivery(mam_sandbox, 0, status="running")
assert "DELIVERED" in res.stdout, res.stdout + res.stderr
def test_s7d_no_started_within_t_is_a_delivery_failure(mam_sandbox):
"""S7d: fail closed, and say so on the job."""
res, published = _run_delivery(mam_sandbox, 0)
assert res.returncode == 1, res.stdout + res.stderr
assert "DELIVERED" not in res.stdout
assert published == ["error"], published
def test_s7e_a_started_from_another_dispatch_is_not_evidence(mam_sandbox):
"""S7e: a loop job keeps one events.log across attempts, so only a started
carrying THIS dispatch token counts."""
res, _ = _run_delivery(mam_sandbox, 0, started_token="tok-OTHER")
assert res.returncode == 1, res.stdout + res.stderr
def test_s8_rc4_is_a_warning_and_the_started_wait_decides(mam_sandbox):
"""S8 (stubbed injection): rc 4 is "Enter not seen accepted", which is
exactly where a still-starting TUI lands - #23's false failure. It must no
longer abort; the started wait decides both ways."""
res, published = _run_delivery(mam_sandbox, 4, started_token="tok-1")
assert "DELIVERED" in res.stdout, res.stdout + res.stderr
assert "rc=4" in res.stderr, res.stderr
assert published == [], published
res, published = _run_delivery(mam_sandbox, 4)
assert res.returncode == 1, res.stdout + res.stderr
assert published == ["error"], published
@pytest.mark.parametrize("rc", [1, 2, 3])
def test_s8b_the_other_injection_failures_still_abort_at_once(mam_sandbox, rc):
"""S8b: rc 1/2/3 say the pane never quiesced, a dialog was blocking, or the
text never appeared. No later `started` repairs those, so they stay hard
failures - only rc 4 was relaxed."""
res, published = _run_delivery(mam_sandbox, rc, started_token="tok-1")
assert res.returncode == 1, res.stdout + res.stderr
assert "DELIVERED" not in res.stdout
assert published == ["error"], published
# --------------------------------------------------------------------------
# item 4 — a rollback verifies the kill (#23)
# --------------------------------------------------------------------------
def _run_rollback(tmp_path, kill_rc, still_alive, row=True, job_id="job1"):
lib = tmp_path / ".agents" / "skills" / "lib.sh"
yaml_path = tmp_path / ".mam" / "agent-sessions.yaml"
if row:
yaml_path.write_text(
"herdr_sessions:\n"
"- name: test-sess\n"
" status: running\n"
" role: creator\n"
" delegate_job_id: %s\n"
" pane:\n"
" index: 0\n"
" pid: 111\n"
" cmd: claude\n"
" cwd: %s\n" % (job_id, tmp_path))
else:
yaml_path.write_text("herdr_sessions: []\n")
_seed_job(tmp_path, job_id)
block = _extract(_create_sh(tmp_path), "# _mark_row_rolled_back <status> <note>",
"trap cleanup_herdr_on_error EXIT")
pub_log = tmp_path / "published.txt"
# The trap is installed and fired the way create_session fires it: an
# errexit shell exiting non-zero. rc 9 through means "no exit 43".
script = '''
set -euo pipefail
source "%s"
SESSION_NAME=test-sess
DELEGATE_JOB_ID=%s
DELEGATE_JOB_TOKEN=tok-1
DELEGATE_JOB_ATTEMPT=1
ROW_APPENDED=%d
AGENT_SESSIONS_YAML="%s"
delegate_publish_event() { printf '%%s\\n' "$2" >> "%s"; }
_herdr() {
case "${1:-}" in
kill-session) return %d ;;
has-session) return %d ;;
esac
return 0
}
%s
exit 9
''' % (lib, job_id, 1 if row else 0, yaml_path, pub_log,
kill_rc, 0 if still_alive else 1, block)
env = dict(os.environ, MAM_JOBS_DIR=str(tmp_path / ".mam" / "jobs"),
AGENT_SESSIONS_YAML=str(yaml_path))
res = subprocess.run(["bash", "-c", script], capture_output=True, text=True,
cwd=str(tmp_path), env=env)
published = pub_log.read_text().split() if pub_log.exists() else []
return res, published, yaml_path.read_text()
def test_s9_a_kill_that_left_the_session_alive_is_reported(mam_sandbox):
"""S9 (stubbed herdr, real YAML + registry): the kill failed and the
session is still up. #23's rollback swallowed exactly this and printed
"rolled back" anyway, leaving a `running` row against a failed job."""
res, published, yaml_text = _run_rollback(mam_sandbox, kill_rc=1, still_alive=True)
assert res.returncode == 43, res.stdout + res.stderr
assert "test-sess" in res.stderr and "kill-session" in res.stderr
assert "rollback-failed" in yaml_text, yaml_text
assert "status: running" in yaml_text, "a session that is still up must not be called gone"
assert "delegate_job_id: null" in yaml_text, yaml_text
assert published == ["cancelled"], published
def test_s10_a_successful_kill_keeps_the_previous_behaviour(mam_sandbox):
"""S10: nothing is still running, so no exit 43 and no warning - but the
row and the job are still cleaned up, which is the other half of #23."""
res, published, yaml_text = _run_rollback(mam_sandbox, kill_rc=0, still_alive=False)
assert res.returncode == 9, res.stdout + res.stderr
assert "rolled-back" in yaml_text, yaml_text + "\nSTDERR:" + res.stderr
assert "status: terminated" in yaml_text, yaml_text
assert "delegate_job_id: null" in yaml_text, yaml_text
assert published == ["cancelled"], published
def test_s10b_a_rollback_before_the_row_existed_touches_no_yaml(mam_sandbox):
"""S10b: failing before the append must not invent a row."""
res, published, yaml_text = _run_rollback(mam_sandbox, kill_rc=0, still_alive=False,
row=False)
assert res.returncode == 9, res.stdout + res.stderr
assert "herdr_sessions: []" in yaml_text, yaml_text