diff --git a/qa/dryrun_coldopen_timeout_proof.sh b/qa/dryrun_coldopen_timeout_proof.sh index 0c2d737d..91598206 100755 --- a/qa/dryrun_coldopen_timeout_proof.sh +++ b/qa/dryrun_coldopen_timeout_proof.sh @@ -9,12 +9,16 @@ # `timeout` wrapper VERBATIM — scripts/play.sh dm_turn AND scripts/play_party.sh turn() — plus the # player / companion facade turn (which is NEVER wrapped in a per-beat timeout), with a stub # `timeout`+`claude` that just prints the argv they would have run. We assert: -# (1) the COLD-OPEN DM argv is `timeout 400 claude …` (default cold-open deadline); -# (2) a ROUTINE/continuing DM argv is `timeout 200 claude …` (routine deadline, unchanged); +# (1) the COLD-OPEN DM argv is `timeout claude …` (model-aware cold-open deadline: opus 500, +# non-opus 550 — F12-2); +# (2) a ROUTINE/continuing DM argv is `timeout 360 claude …` (routine deadline — F12-1 raised the +# flat 200s to 360s; this proof is updated to match); # (3) the env override works: WORLDOS_COLDOPEN_TIMEOUT bumps the cold open, CLAWDND_BEAT_TIMEOUT # bumps the routine tier, independently; # (4) the PLAYER / COMPANION turn argv has NO `timeout` wrapper at all (player turn unaffected); -# (5) the SAME resolved deadline (not the stale global) is echoed in the retry log line. +# (5) the SAME resolved deadline (not the stale global) is echoed in the retry log line; +# (6) F12-2 model-aware cold-open margin: opus cold open = 500, sonnet (non-opus) cold open = 550 +# (the sonnet default cleared its documented 400s band top, the thin-margin bug). set -uo pipefail ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" . "$ROOT/qa/lib_beat_driver.sh" @@ -76,44 +80,56 @@ party_turn_argv() { hr() { printf '\n========== %s ==========\n' "$1"; } -hr "S1 play.sh COLD OPEN (first=1), no env -> timeout 400" +# Default CLAWDND_DM_MODEL here is "sonnet" (set above) -> the cold-open default is the non-opus 550s. +hr "S1 play.sh COLD OPEN (first=1, sonnet), no env -> timeout 550" out1="$(play_dm_turn_argv 1 'Begin the session.')"; printf '%s\n' "$out1" -hr "S2 play.sh ROUTINE beat (first=0), no env -> timeout 200" +hr "S2 play.sh ROUTINE beat (first=0), no env -> timeout 360" out2="$(play_dm_turn_argv 0 'The player does: opens the door.')"; printf '%s\n' "$out2" hr "S3 play.sh COLD OPEN + WORLDOS_COLDOPEN_TIMEOUT=600 -> timeout 600" out3="$(WORLDOS_COLDOPEN_TIMEOUT=600 play_dm_turn_argv 1 'Begin the session.')"; printf '%s\n' "$out3" hr "S4 play.sh ROUTINE + CLAWDND_BEAT_TIMEOUT=150 -> timeout 150 (cold open unaffected)" out4="$(CLAWDND_BEAT_TIMEOUT=150 play_dm_turn_argv 0 'The player does: opens the door.')"; printf '%s\n' "$out4" -hr "S5 play_party.sh COLD OPEN DM (first=1) -> timeout 400" +hr "S5 play_party.sh COLD OPEN DM (first=1, sonnet) -> timeout 550" out5="$(party_turn_argv dm 1 'You are the Dungeon Master. Begin.' "$DSID")"; printf '%s\n' "$out5" -hr "S6 play_party.sh ROUTINE DM beat (first=0) -> timeout 200" +hr "S6 play_party.sh ROUTINE DM beat (first=0) -> timeout 360" out6="$(party_turn_argv dm 0 'This beat, the party acts.' "$DSID")"; printf '%s\n' "$out6" hr "S7 play_party.sh COMPANION facade turn -> NO timeout wrapper (player turn unaffected)" out7="$(party_turn_argv actor 0 'Take your action through your tools.' "$CSID" "$COMP_CFG")"; printf '%s\n' "$out7" +# F12-2: the cold-open deadline is model-aware. Opus (the DEFAULT DM model in every lane) -> 500; +# sonnet / any non-opus (the explicit A/B opt-in) -> 550 (cleared the 400s band-top thin-margin bug). +hr "S8 play.sh COLD OPEN with CLAWDND_DM_MODEL=opus -> timeout 500" +out8="$(CLAWDND_DM_MODEL=opus play_dm_turn_argv 1 'Begin the session.')"; printf '%s\n' "$out8" +hr "S9 play.sh COLD OPEN with CLAWDND_DM_MODEL=sonnet -> timeout 550 (NOT the old 400 band-top)" +out9="$(CLAWDND_DM_MODEL=sonnet play_dm_turn_argv 1 'Begin the session.')"; printf '%s\n' "$out9" # ---- Assertions ------------------------------------------------------------------- hr "ASSERTIONS" fail=0 chk() { if eval "$2"; then echo "PASS: $1"; else echo "FAIL: $1"; fail=1; fi; } -# (1) cold open -> 400; (2) routine -> 200; and the cold open is NOT 200 (the bug it fixes). -chk "S1 play.sh cold open wraps timeout 400" 'printf "%s" "$out1" | grep -q -- "TIMEOUT-WRAP «400»"' -chk "S1 play.sh cold open is NOT timeout 200" '! printf "%s" "$out1" | grep -q -- "TIMEOUT-WRAP «200»"' +# (1) cold open (sonnet) -> 550; (2) routine -> 360; and the cold open is NOT the routine 360 (tiered). +chk "S1 play.sh cold open wraps timeout 550" 'printf "%s" "$out1" | grep -q -- "TIMEOUT-WRAP «550»"' +chk "S1 play.sh cold open is NOT routine 360" '! printf "%s" "$out1" | grep -q -- "TIMEOUT-WRAP «360»"' chk "S1 play.sh cold open still has --effort max" 'printf "%s" "$out1" | grep -A1 -- "«--effort»" | grep -q -- "«max»"' -chk "S2 play.sh routine wraps timeout 200" 'printf "%s" "$out2" | grep -q -- "TIMEOUT-WRAP «200»"' +chk "S2 play.sh routine wraps timeout 360" 'printf "%s" "$out2" | grep -q -- "TIMEOUT-WRAP «360»"' chk "S2 play.sh routine still --effort medium" 'printf "%s" "$out2" | grep -A1 -- "«--effort»" | grep -q -- "«medium»"' # (3) env overrides, independent per tier. chk "S3 WORLDOS_COLDOPEN_TIMEOUT=600 -> timeout 600" 'printf "%s" "$out3" | grep -q -- "TIMEOUT-WRAP «600»"' chk "S4 CLAWDND_BEAT_TIMEOUT=150 -> routine timeout 150" 'printf "%s" "$out4" | grep -q -- "TIMEOUT-WRAP «150»"' -# (5) retry log line uses the RESOLVED deadline (400 on the cold open, 200 on routine) — not stale. -chk "S1 retry log line says timeout=400s" 'printf "%s" "$out1" | grep -q -- "timeout=400s"' -chk "S2 retry log line says timeout=200s" 'printf "%s" "$out2" | grep -q -- "timeout=200s"' +# (5) retry log line uses the RESOLVED deadline (the cold open's, the routine's) — not stale. +chk "S1 retry log line says timeout=550s" 'printf "%s" "$out1" | grep -q -- "timeout=550s"' +chk "S2 retry log line says timeout=360s" 'printf "%s" "$out2" | grep -q -- "timeout=360s"' # play_party parity. -chk "S5 play_party cold open wraps timeout 400" 'printf "%s" "$out5" | grep -q -- "TIMEOUT-WRAP «400»"' -chk "S6 play_party routine wraps timeout 200" 'printf "%s" "$out6" | grep -q -- "TIMEOUT-WRAP «200»"' +chk "S5 play_party cold open wraps timeout 550" 'printf "%s" "$out5" | grep -q -- "TIMEOUT-WRAP «550»"' +chk "S6 play_party routine wraps timeout 360" 'printf "%s" "$out6" | grep -q -- "TIMEOUT-WRAP «360»"' # (4) the player / companion facade turn is NEVER timeout-wrapped (player turn unaffected). chk "S7 companion turn has NO timeout wrapper" '! printf "%s" "$out7" | grep -q -- "TIMEOUT-WRAP"' chk "S7 companion turn still runs claude" 'printf "%s" "$out7" | grep -q -- "CLAUDE-ARGV-BEGIN"' +# (6) F12-2 model-aware cold-open margin: opus -> 500 (unchanged, the shipped default); sonnet -> 550 +# (the bump). The sonnet cold open must NOT be the old 400s band-top — the thin-margin bug. +chk "S8 opus cold open wraps timeout 500" 'printf "%s" "$out8" | grep -q -- "TIMEOUT-WRAP «500»"' +chk "S9 sonnet cold open wraps timeout 550" 'printf "%s" "$out9" | grep -q -- "TIMEOUT-WRAP «550»"' +chk "S9 sonnet cold open is NOT the old 400 band-top" '! printf "%s" "$out9" | grep -q -- "TIMEOUT-WRAP «400»"' hr "RESULT" [ "$fail" = 0 ] && echo "ALL ASSERTIONS PASSED" || echo "SOME ASSERTIONS FAILED" diff --git a/qa/lib_beat_driver.sh b/qa/lib_beat_driver.sh index 13ef42d0..d17bb4de 100644 --- a/qa/lib_beat_driver.sh +++ b/qa/lib_beat_driver.sh @@ -622,16 +622,17 @@ clawdnd_dm_effort_arg() { # • the COLD OPEN (first != 0) is the one-time, --effort max, full world-build — generate the # world, scene, PC, opening NPCs + portraits. That MAX-EFFORT cold open routinely runs ~280–400s; # the routine deadline KILLS it mid-build (the masked "cold-open reproducibly broken" mode), -# so the cold open gets a generous deadline: WORLDOS_COLDOPEN_TIMEOUT (default 400s). +# so the cold open gets a generous, model-aware deadline: WORLDOS_COLDOPEN_TIMEOUT +# (default 500s opus / 550s non-opus — see the F12-2 note in clawdnd_dm_timeout below). # • CONTINUING / routine beats (first = 0) are --effort medium and resolve one move against # established canon — faster — so they get the per-beat deadline CLAWDND_BEAT_TIMEOUT # (default 360s — see the F12-1 note below). -# Keyed off the SAME `first` signal as the effort + lean levers, so cold-open=full+max+400s and the -# long tail=lean+medium+360s stay in lock-step. Applies ONLY to the DM turn (player/companion turns +# Keyed off the SAME `first` signal as the effort + lean levers, so cold-open=full+max+(500/550)s and +# the long tail=lean+medium+360s stay in lock-step. Applies ONLY to the DM turn (player/companion turns # are never wrapped in a per-beat timeout at all). # # Both knobs resolve through the same WORLDOS_/CLAWDND_ fallback as everything else (worldos_env): -# WORLDOS_COLDOPEN_TIMEOUT (default 400) — the cold open's deadline, in seconds. +# WORLDOS_COLDOPEN_TIMEOUT (default 500 opus / 550 non-opus) — the cold open's deadline, in seconds. # CLAWDND_BEAT_TIMEOUT (default 360) — every continuing beat's deadline (today's knob, kept). # Note: CLAWDND_BEAT_TIMEOUT keeps its CLAWDND_ name (it predates the WorldOS rename and is the # documented routine knob); only the NEW cold-open knob takes the WORLDOS_ name. worldos_env still @@ -648,9 +649,16 @@ clawdnd_dm_effort_arg() { clawdnd_dm_timeout() { local first="$1" if [ "$first" != "0" ]; then - # Cold-open deadline is model-aware. Opus-high cold-open measured ~300s; give it margin (500s) for - # per-world/per-run variance so it is never killed mid-build. Sonnet keeps 400s (max runs ~280–400s). - local _co_timeout=400 + # Cold-open deadline is model-aware. Opus-high cold-open measured ~300s here; give it margin (500s) + # for per-world/per-run variance so it is never killed mid-build. + # F12-2 (audit 2026-06-11): the NON-opus default was 400s — but a sonnet max-effort cold open's + # OWN documented band is "~280–400s" (the prior comment), so 400 == the band TOP (zero margin vs + # the band, ~8% vs the 370s measured max) and a slow sonnet cold open was killed at the same mark + # the band predicted. Bump the non-opus default to 550s (~38% over the 400 band-top), so the sonnet + # A/B arm gets proportional margin to opus's (opus: 500 vs ~300 measured ≈ +67%; sonnet: 550 vs 400 + # band-top ≈ +38%). Opus is unchanged (still the default DM model in every lane), so the shipped + # path is byte-identical; only the explicit sonnet opt-in widens. Env override still wins unchanged. + local _co_timeout=550 case "${CLAWDND_DM_MODEL:-}" in *opus*) _co_timeout=500 ;; esac worldos_env COLDOPEN_TIMEOUT "$_co_timeout" else @@ -717,6 +725,78 @@ except KeyboardInterrupt: ' "$_secs" "$@" } +# PROVIDER-STATUS SIDECAR (F12-10): write the provider lifecycle sidecar the OpenWorlds viewer reads +# (provider_status.json, schema worldos.provider-status.v1). Before this, ONLY the codex DM wrapper +# wrote it; the CLAUDE lanes (scripts/play.sh + scripts/play_party.sh) never did, so on a turn-cap / +# budget stop or a crash the viewer fell back to status "unknown" — which is NOT in the +# {stopped,failed,exhausted} set the viewer buckets as `no_provider` (viewer/server.py), so the app +# showed a live-looking-but-dead dashboard instead of the "DM provider is no longer running" surface. +# This is the ONE shared writer for the claude lanes (the codex wrapper keeps its own richer copy with +# the seed fixture). The sidecar is DERIVED / atomic state, NOT campaign state — it is the viewer's +# read-only health view, never read back as truth — so writing it does not violate engine-sole-writer. +# +# Atomic: write a sibling tmp under the SAME dir, fsync, replace, fsync the dir — so a concurrent +# viewer read never sees a torn file. Reads ambient globals with safe defaults (every field the +# viewer's _provider_status_summary expects), so a caller that hasn't set a field still writes a valid +# row. Best-effort: a write failure never fails a beat (returns 0). Bash 3.2-clean: standalone python +# (no heredoc-in-$()), no arrays. $1=PROVIDER_STATUS path $2=status $3=reason $4=detail $5=turns +# $6=wrapper-name (optional; defaults to the calling script's basename — display-only field). +clawdnd_write_provider_status() { + local path="$1" status="$2" reason="$3" detail="$4" turns="${5:-0}" wrapper="${6:-${BASH_SOURCE[1]:-}}" + local provider model max_turns sha actor_model scorer_model + provider="$(worldos_env PROVIDER claude)" + model="$(worldos_env DM_MODEL '')" + actor_model="$(worldos_env ACTOR_MODEL '')" + scorer_model="$(worldos_env SCORER_MODEL '')" + max_turns="${MAX_TURNS:-}" + sha="${WORLDOS_BUILD_SHA:-${CLAWDND_BUILD_SHA:-$(git rev-parse --short HEAD 2>/dev/null || printf 'unknown')}}" + python3 - "$path" "$status" "$reason" "$detail" "$provider" "$model" "$actor_model" "$scorer_model" "$max_turns" "$turns" "$sha" "$wrapper" 2>/dev/null <<'PY' || true +import json, os, sys, time +from pathlib import Path +(path, status, reason, detail, provider, model, actor_model, scorer_model, + max_turns, turns, sha, wrapper) = sys.argv[1:] +path = Path(path) +wrapper_name = os.path.basename(wrapper) or wrapper or "play.sh" +payload = { + "schema": "worldos.provider-status.v1", + "provider": provider, + "provider_family": "anthropic-claude" if "codex" not in provider.lower() else "codex-openai", + "auth_surface": "claude-cli", + "model": model, + "player_model": actor_model, + "scorer_model": scorer_model, + "wrapper": ("scripts/%s" % wrapper_name) if not wrapper_name.startswith("scripts/") else wrapper_name, + "fixture": {}, + "status": status, + "reason": reason, + "detail": detail, + "max_turns": int(max_turns) if str(max_turns).isdigit() else (max_turns or None), + "dm_turns": int(turns) if str(turns).isdigit() else turns, + "updated_at": time.time(), +} +try: + path.parent.mkdir(parents=True, exist_ok=True) + tmp = path.with_name(".%s.%s.tmp" % (path.name, os.getpid())) + with tmp.open("w", encoding="utf-8") as fh: + fh.write(json.dumps(payload, indent=2, sort_keys=True) + "\n") + fh.flush() + os.fsync(fh.fileno()) + tmp.replace(path) + try: + dfd = os.open(str(path.parent), os.O_RDONLY) + except OSError: + dfd = None + if dfd is not None: + try: + os.fsync(dfd) + finally: + os.close(dfd) +except OSError: + sys.exit(0) +PY + return 0 +} + # RE-MINT SESSION ON RETRY (the ONE shared implementation of "never reuse a CONSUMED session id"). # A `claude -p` attempt that fails AFTER startup STILL registered its --session-id on disk # (~/.claude/projects//.jsonl), so a retry that re-passes that SAME --session-id dies diff --git a/qa/run_duo.sh b/qa/run_duo.sh index 6c4bd99b..429e80f6 100755 --- a/qa/run_duo.sh +++ b/qa/run_duo.sh @@ -162,11 +162,30 @@ turn() { # signal as lean. DM turn ONLY — the player branch below never gets --effort. clawdnd_dm_effort_arg "$first" out="$T/$RUN.dm.$(date +%s%N).jsonl" - claude -p "$msg" ${resume[@]+"${resume[@]}"} ${extra[@]+"${extra[@]}"} --plugin-dir "$ROOT" --mcp-config "$DM_CFG" --strict-mcp-config \ - --model "$CLAWDND_DM_MODEL" ${CLAWDND_DM_EFFORT[@]+"${CLAWDND_DM_EFFORT[@]}"} --permission-mode bypassPermissions --max-budget-usd "$BUDGET" \ - --output-format stream-json --verbose > "$out" 2>> "$T/$RUN.dm.err" + # F12-11 (audit 2026-06-11): the DM turn was UNBOUNDED here — run_duo had no per-beat deadline at + # all, so a wedged DM beat (hung MCP startup, a stuck model call) hung the whole sweep, and + # turn_retry's empty-output retry never fired because a hang never RETURNS empty (it never + # returns). Bound the DM turn through the SAME worldos_timeout shim + clawdnd_dm_timeout tier the + # product lanes use (cold-open vs routine, model-aware), so a hang is killed at the deadline (rc=124) + # → no result event → clawdnd_dm_final_text echoes empty → turn_retry's empty-output retry fires. + # Player turn stays unbounded (it is a fast facade turn and was never the hang source). + local beat_timeout; beat_timeout="$(clawdnd_dm_timeout "$first")" + worldos_timeout "$beat_timeout" \ + claude -p "$msg" ${resume[@]+"${resume[@]}"} ${extra[@]+"${extra[@]}"} --plugin-dir "$ROOT" --mcp-config "$DM_CFG" --strict-mcp-config \ + --model "$CLAWDND_DM_MODEL" ${CLAWDND_DM_EFFORT[@]+"${CLAWDND_DM_EFFORT[@]}"} --permission-mode bypassPermissions --max-budget-usd "$BUDGET" \ + --output-format stream-json --verbose > "$out" 2>> "$T/$RUN.dm.err" rc=$? cat "$out" >> "$COMBINED" + # F12-11: surface the REAL failure cause on a nonzero rc with NO error-class result (a timeout + # rc=124 writes no result event; a CLI crash; a rate-limit exit) — these were MASKED because + # clawdnd_dm_final_text below reports only an error-class RESULT event, so a hang/timeout left the + # structured cause buried in $out and the duo loop showed only "empty turn". The + # is-error guard avoids a DOUBLE report when the result IS error-class (final_text handles that + # one). Read-only; echoes a "[dm-attempt] …" reason (+ the 401/403 re-auth hint) to stderr. The + # rc==0 path is byte-identical to before. + if [ "$rc" -ne 0 ] && ! clawdnd_dm_result_is_error "$out"; then + clawdnd_report_attempt_failure "$out" "$rc" + fi # SYN-01: the shared classification front door (qa/lib_beat_driver.sh) — notes $out for the # caller's clawdnd_resolve_dm_reply and echoes NOTHING on an error-class result (a 401's # "result" text is the API's error string, never a reply), so turn_retry's empty-only retry @@ -192,11 +211,19 @@ turn_retry() { if [ -z "$r" ]; then echo "[duo] empty turn ($1) — retrying once…" >&2 # A cold-open ($3=1) retry must NOT reuse $2's already-registered --session-id (a failed but - # registered attempt → "Session ID … is already in use." → empty output again). Re-mint a fresh - # id for the retry. Continuing beats ($3=0) use --resume (safe to repeat); lean continuing beats - # already mint their own fresh id inside turn(), so only the cold open needs a swap here. + # registered attempt → "Session ID … is already in use." → empty output again). F12-11: re-mint + # via the SHARED clawdnd_dm_remint_session_on_retry (qa/lib_beat_driver.sh) — the SAME re-mint + # implementation scripts/play.sh + play_party.sh use, so the three harnesses can't drift. The + # helper inspects the prior turn's resume MODE (which `turn` built from $3): on a cold open the + # mode is `--session-id $2`, so it populates CLAWDND_DM_RETRY_SESSION with a FRESH `--session-id + # ` we hand back to turn as the new sid. Continuing beats ($3=0) use --resume (safe to + # repeat) — the helper leaves the array empty and we retry verbatim; lean continuing beats already + # mint their own fresh id inside turn(). The empty-output trigger above is preserved (it now ALSO + # fires on a timeout, which clawdnd_dm_final_text turns into an empty reply). if [ "${3:-}" = "1" ]; then - local _fresh; _fresh="$(uuidgen 2>/dev/null || python3 -c 'import uuid;print(uuid.uuid4())')" + clawdnd_dm_remint_session_on_retry --session-id "$2" + local _fresh="$2" + [ "${#CLAWDND_DM_RETRY_SESSION[@]}" -ge 2 ] && _fresh="${CLAWDND_DM_RETRY_SESSION[1]}" r="$(turn "$1" "$_fresh" "$3" "${@:4}")" else r="$(turn "$@")" diff --git a/qa/test_play_party_actor_timeout.sh b/qa/test_play_party_actor_timeout.sh new file mode 100755 index 00000000..7341aae0 --- /dev/null +++ b/qa/test_play_party_actor_timeout.sh @@ -0,0 +1,83 @@ +#!/usr/bin/env bash +# BEHAVIORAL TEST (no model call): proves scripts/play_party.sh's COMPANION facade turn is now +# bounded by a per-beat deadline (F12-2 audit finding F12-12). Before this, the actor branch of +# turn() ran a BARE `claude -p` with no `timeout`, so a wedged companion blocked companion_moves — +# which runs BEFORE the DM turn each beat — indefinitely (the human move was acknowledged, the +# cursor advanced, but nothing resolved). The DM branch was already wrapped; the companion was not. +# +# We source the REAL qa/lib_beat_driver.sh (for worldos_timeout) and reproduce the actor branch of +# play_party.sh turn() VERBATIM, with stub `claude`/`worldos_timeout` that print the argv. We assert: +# (1) the COMPANION argv IS wrapped: `worldos_timeout 120 claude …` (the default actor deadline); +# (2) WORLDOS_ACTOR_TIMEOUT overrides the deadline; +# (3) a HUNG companion (sleep-forever stub) is killed within the deadline AND yields EMPTY output +# (so companion_moves' `[ -n "$cm" ] &&` guard skips it — graceful degradation, beat survives); +# (4) the deadline is SHORT enough that the kill is observable (well under a wall-clock budget). +# Self-contained under mktemp; safe on macOS dev box AND ubuntu CI (worldos_timeout falls back to a +# python3 subprocess when timeout(1) is absent, with the same rc=124 deadline semantics). +set -uo pipefail +ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" +. "$ROOT/qa/lib_beat_driver.sh" + +TMP="$(mktemp -d)"; trap 'rm -rf "$TMP"' EXIT +STATE_DIR="$TMP/state"; mkdir -p "$STATE_DIR" +COMBINED="$STATE_DIR/dm.combined.jsonl"; : > "$COMBINED" +CLAWDND_ACTOR_MODEL="sonnet"; BUDGET="1.50" +CSID="CSID-fixed-0000"; COMP_CFG="$TMP/companion_0.mcp.json"; : > "$COMP_CFG" + +fail=0 +chk() { if eval "$2"; then echo "PASS: $1"; else echo "FAIL: $1"; fail=1; fi; } + +# ---- VERBATIM: scripts/play_party.sh turn() ACTOR branch (F12-12 timeout-wrapped) ------------- +# Mirrors the else-branch of turn(): out path -> worldos_timeout-wrapped claude -p (stdout -> $out) -> +# cost append -> the jq result extraction. $1=msg $2=sid $3=cfg. Echoes $out so the argv-capture +# probe (which writes TIMEOUT-WRAP/CLAUDE-ARGV into $out via the same redirect the real branch uses) +# can be inspected. The real branch's stdout-to-file redirect is exactly why we read the FILE, not the +# function's own stdout, to see the wrapped argv. +ACTOR_OUT="" +party_actor_turn() { + local msg="$1" sid="$2" cfg="$3" out resume + resume=(--resume "$sid") + out="$STATE_DIR/companion.$(date +%s%N).jsonl" + worldos_timeout "${WORLDOS_ACTOR_TIMEOUT:-${CLAWDND_ACTOR_TIMEOUT:-120}}" \ + claude -p "$msg" "${resume[@]}" --mcp-config "$cfg" --strict-mcp-config \ + --model "$CLAWDND_ACTOR_MODEL" --permission-mode bypassPermissions --max-budget-usd "$BUDGET" \ + --output-format stream-json --verbose > "$out" 2>> "$STATE_DIR/companion.err" || true + ACTOR_OUT="$out" + cat "$out" >> "$COMBINED" + jq -rs 'map(select(.type=="result"))[-1].result // ""' "$out" 2>/dev/null +} + +# (1)+(2): argv capture. Stub claude prints its argv in «»; stub worldos_timeout prints the deadline +# then exec-through (overrides the lib's for this argv-only probe). The real actor branch redirects +# stdout to $out, so the captured argv lands in the file ACTOR_OUT, not the function's stdout. +claude() { printf 'CLAUDE-ARGV-BEGIN\n'; local a; for a in "$@"; do printf ' «%s»\n' "$a"; done; printf 'CLAUDE-ARGV-END\n'; } +worldos_timeout() { printf 'TIMEOUT-WRAP «%s»\n' "$1"; shift; "$@"; } + +party_actor_turn 'Take your action.' "$CSID" "$COMP_CFG" >/dev/null; argv_default="$(cat "$ACTOR_OUT")" +chk "companion turn IS wrapped by worldos_timeout" 'printf "%s" "$argv_default" | grep -q -- "TIMEOUT-WRAP"' +chk "default actor deadline is 120s" 'printf "%s" "$argv_default" | grep -q -- "TIMEOUT-WRAP «120»"' +chk "companion turn still runs claude" 'printf "%s" "$argv_default" | grep -q -- "CLAUDE-ARGV-BEGIN"' +WORLDOS_ACTOR_TIMEOUT=45 party_actor_turn 'Take your action.' "$CSID" "$COMP_CFG" >/dev/null; argv_env="$(cat "$ACTOR_OUT")" +chk "WORLDOS_ACTOR_TIMEOUT=45 overrides the deadline" 'printf "%s" "$argv_env" | grep -q -- "TIMEOUT-WRAP «45»"' + +# (3)+(4): a HUNG companion is actually killed within the deadline and yields empty. Use the REAL +# worldos_timeout (re-source to drop the argv-stub override) with a sleep-forever `claude` stub and a +# 2s deadline. worldos_timeout execs `claude` as an EXTERNAL command (a bash function is invisible to +# timeout(1)/the python3 subprocess), so the wedged stub is a real EXECUTABLE on PATH. Assert: returns +# empty, returns FAST (the no-timeout branch would hang ~forever), result file holds no result event. +unset -f worldos_timeout +. "$ROOT/qa/lib_beat_driver.sh" # restore the real shim +BIN="$TMP/bin"; mkdir -p "$BIN"; PATH="$BIN:$PATH" +cat > "$BIN/claude" <<'STUB' +#!/usr/bin/env bash +sleep 600 +STUB +chmod +x "$BIN/claude" +start=$SECONDS +hung="$(WORLDOS_ACTOR_TIMEOUT=2 party_actor_turn 'Take your action.' "$CSID" "$COMP_CFG")" +elapsed=$((SECONDS - start)) +chk "hung companion turn yields EMPTY (skip-safe)" '[ -z "$hung" ]' +chk "hung companion turn is KILLED at the deadline (<=10s, not 600s)" '[ "$elapsed" -le 10 ]' + +[ "$fail" = 0 ] && echo "ALL ASSERTIONS PASSED" || echo "SOME ASSERTIONS FAILED" +exit "$fail" diff --git a/qa/test_play_party_single_flight.sh b/qa/test_play_party_single_flight.sh index bb2e94cc..91732ad2 100755 --- a/qa/test_play_party_single_flight.sh +++ b/qa/test_play_party_single_flight.sh @@ -81,5 +81,34 @@ else echo "PASS: read-only-dir spin guard (skipped — running as root bypasses dir perms)" fi +# (6) F12-13: scripts/play.sh (the .app's DEFAULT solo entry point) must ALSO acquire + release this +# lock — before, only play_party.sh did, and on the solo path it `exec play.sh` AFTER acquiring, +# so a solo launch had NO lock and two solo launches stacked two viewers + two DM sessions. These +# are static-wiring assertions on the real script (a runtime launch needs claude + a viewer). +PLAY="$ROOT/scripts/play.sh" +chk "play.sh acquires the single-flight launch lock" 'grep -q "clawdnd_acquire_launch_lock" "$PLAY"' +chk "play.sh releases the lock in cleanup" 'grep -q "clawdnd_release_launch_lock" "$PLAY"' +chk "play.sh acquire is guarded (declare -F) like play_party" 'grep -q "declare -F clawdnd_acquire_launch_lock" "$PLAY"' +chk "play.sh acquire precedes the viewer supervisor" '[ "$(grep -n "clawdnd_acquire_launch_lock" "$PLAY" | head -1 | cut -d: -f1)" -lt "$(grep -n "viewer_supervisor &" "$PLAY" | head -1 | cut -d: -f1)" ]' + +# (7) F12-13: play.sh has an IDLE CEILING (was spinning `sleep 2` forever with no player). Static + +# a hermetic runtime check of the idle-break logic extracted VERBATIM from play.sh's loop tail. +chk "play.sh defines MAX_IDLE from CLAWDND_PLAY_MAX_IDLE" 'grep -q "MAX_IDLE=.*CLAWDND_PLAY_MAX_IDLE" "$PLAY"' +chk "play.sh idle-break echoes the stop reason" 'grep -q "idle .* with no player move — stopping" "$PLAY"' +# Hermetic idle-break: mirror the loop's else-branch (no claude/viewer). With MAX_IDLE=1 and no move, +# the loop must BREAK within a few seconds, not spin forever. A watchdog turns a regression into a +# FAIL, not a hang. +( SECONDS=0; MAX_IDLE=1; last_activity=$SECONDS + while true; do + if [ $((SECONDS - last_activity)) -ge "$MAX_IDLE" ]; then echo "BROKE"; break; fi + sleep 1 + done > "$TMP/idle.out" ) & ipid=$! +for _ in $(seq 1 60); do kill -0 "$ipid" 2>/dev/null || break; sleep 0.1; done +if kill -0 "$ipid" 2>/dev/null; then + kill "$ipid" 2>/dev/null; echo "FAIL: idle ceiling did not break within 6s (regression: would spin forever)"; fail=1 +else + chk "idle ceiling breaks the loop when MAX_IDLE elapses" 'grep -q "BROKE" "$TMP/idle.out"' +fi + [ "$fail" = 0 ] && echo "ALL ASSERTIONS PASSED" || echo "SOME ASSERTIONS FAILED" exit "$fail" diff --git a/qa/test_provider_status_claude_lanes.sh b/qa/test_provider_status_claude_lanes.sh new file mode 100755 index 00000000..d4764267 --- /dev/null +++ b/qa/test_provider_status_claude_lanes.sh @@ -0,0 +1,82 @@ +#!/usr/bin/env bash +# BEHAVIORAL TEST (no model call): proves the CLAUDE lanes now write the provider-status sidecar the +# OpenWorlds viewer reads (F12-2 audit finding F12-10). Before this, only scripts/play_codex_dm.sh +# wrote provider_status.json; scripts/play.sh + scripts/play_party.sh never did, so on a turn-cap / +# budget stop or a crash the viewer fell back to status "unknown" (NOT in the {stopped,failed, +# exhausted} set it buckets as `no_provider`) → a live-looking-but-dead dashboard. +# +# It sources the REAL qa/lib_beat_driver.sh and drives clawdnd_write_provider_status + the lanes' +# clean-stop / crash-trap LOGIC (extracted verbatim) against a throwaway $STATE_DIR. We assert: +# (1) "running" at start is a valid worldos.provider-status.v1 row; +# (2) a clean TURN-CAP stop writes status=stopped reason=turn_cap (the no_provider bucket) and sets +# the clean-stop flag so the crash trap does NOT relabel it "failed"; +# (3) the crash trap writes status=failed when the run did NOT stop cleanly; +# (4) the crash trap is a NO-OP after a clean stop (preserves "stopped"); +# (5) the row carries the fields the viewer's _provider_status_summary expects. +# It ALSO statically asserts both real lanes wire the start / stopped / failed writes. Self-contained +# under mktemp; safe on macOS dev box AND ubuntu CI. +set -uo pipefail +ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" +. "$ROOT/qa/lib_beat_driver.sh" + +TMP="$(mktemp -d)"; trap 'rm -rf "$TMP"' EXIT +STATE_DIR="$TMP/state"; mkdir -p "$STATE_DIR" +PROVIDER_STATUS="$STATE_DIR/provider_status.json" +PROVIDER=claude WORLDOS_DM_MODEL=opus MAX_TURNS=40 +export PROVIDER WORLDOS_DM_MODEL MAX_TURNS + +fail=0 +chk() { if eval "$2"; then echo "PASS: $1"; else echo "FAIL: $1"; fail=1; fi; } +field() { python3 -c 'import json,sys; print(json.load(open(sys.argv[1])).get(sys.argv[2]))' "$PROVIDER_STATUS" "$1" 2>/dev/null; } + +# Mirror the lanes' thin wrapper + clean-stop flag + crash trap. +DM_TURNS=3; PROVIDER_STOPPED_CLEANLY=0 +provider_status_set() { clawdnd_write_provider_status "$PROVIDER_STATUS" "$1" "$2" "$3" "$DM_TURNS" "scripts/play.sh"; } +crash_trap() { + if [ "${PROVIDER_STOPPED_CLEANLY:-0}" != "1" ] && [ -n "${PROVIDER_STATUS:-}" ]; then + clawdnd_write_provider_status "$PROVIDER_STATUS" failed crashed "DM exited unexpectedly." "${DM_TURNS:-0}" "scripts/play.sh" + fi +} + +# (1) start → running, valid v1. +provider_status_set running active "DM is running." +chk "start row exists" '[ -f "$PROVIDER_STATUS" ]' +chk "start schema is worldos.provider-status.v1" '[ "$(field schema)" = "worldos.provider-status.v1" ]' +chk "start status is running" '[ "$(field status)" = "running" ]' +chk "running is NOT a no_provider bucket" 'case "$(field status)" in stopped|failed|exhausted) false;; *) true;; esac' + +# (2) clean turn-cap stop → stopped/turn_cap, flag set. +provider_status_set stopped turn_cap "Max turns reached."; PROVIDER_STOPPED_CLEANLY=1 +chk "turn-cap stop → status=stopped" '[ "$(field status)" = "stopped" ]' +chk "turn-cap stop → reason=turn_cap" '[ "$(field reason)" = "turn_cap" ]' +chk "stopped IS a no_provider bucket" 'case "$(field status)" in stopped|failed|exhausted) true;; *) false;; esac' + +# (4) crash trap after a CLEAN stop is a NO-OP (must not relabel "stopped" as "failed"). +crash_trap +chk "crash trap preserves a clean 'stopped'" '[ "$(field status)" = "stopped" ]' + +# (3) crash WITHOUT a clean stop → failed. +PROVIDER_STOPPED_CLEANLY=0 +provider_status_set running active "DM is running." # back to running (a live session) +crash_trap +chk "crash trap (not clean) → status=failed" '[ "$(field status)" = "failed" ]' +chk "failed IS a no_provider bucket" 'case "$(field status)" in stopped|failed|exhausted) true;; *) false;; esac' + +# (5) the row carries the viewer's expected fields. +chk "row carries provider" '[ "$(field provider)" = "claude" ]' +chk "row carries model (from DM_MODEL)" '[ "$(field model)" = "opus" ]' +chk "row carries dm_turns" '[ "$(field dm_turns)" = "3" ]' +chk "row carries max_turns" '[ "$(field max_turns)" = "40" ]' +chk "row carries wrapper" 'printf "%s" "$(field wrapper)" | grep -q "play"' + +# Static wiring: both real lanes write start / stopped / failed. +for lane in scripts/play.sh scripts/play_party.sh; do + chk "$lane writes a 'running' provider-status" 'grep -q "provider_status_set running" "$ROOT/'"$lane"'"' + chk "$lane writes 'stopped' on a clean stop" 'grep -q "provider_status_set stopped" "$ROOT/'"$lane"'"' + chk "$lane writes 'failed' in its cleanup trap" 'grep -q "clawdnd_write_provider_status .* failed" "$ROOT/'"$lane"'"' +done +# The codex wrapper already wrote it (the lane this finding brings the claude lanes up to). +chk "play_codex_dm still writes provider_status" 'grep -q "provider_status" "$ROOT/scripts/play_codex_dm.sh"' + +[ "$fail" = 0 ] && echo "ALL ASSERTIONS PASSED" || echo "SOME ASSERTIONS FAILED" +exit "$fail" diff --git a/qa/test_run_duo_dm_timeout.sh b/qa/test_run_duo_dm_timeout.sh new file mode 100755 index 00000000..28ad4578 --- /dev/null +++ b/qa/test_run_duo_dm_timeout.sh @@ -0,0 +1,99 @@ +#!/usr/bin/env bash +# BEHAVIORAL TEST (no model call): proves qa/run_duo.sh's DM turn is now (F12-2 audit finding F12-11) +# (1) BOUNDED by a per-beat deadline via worldos_timeout + the model-aware clawdnd_dm_timeout tier +# (cold-open vs routine) — before, the DM branch was an UNBOUNDED `claude -p`, so a wedged beat +# hung the whole sweep and the empty-output retry never fired (a hang never returns empty); +# (2) SURFACES the real failure cause on a nonzero rc with no error-class result (a timeout) AND on +# an error-class 401 result — the "[dm-attempt] …" reason + the 401/403 NOT-retryable re-auth +# hint, instead of masking it as a phantom empty turn; +# (3) re-mints a FRESH cold-open session id on retry via the SHARED helper +# (clawdnd_dm_remint_session_on_retry), not an inline uuid — so the three harnesses can't drift. +# +# It sources the REAL qa/lib_beat_driver.sh and reproduces run_duo.sh's DM branch + turn_retry remint +# VERBATIM with stub claude/worldos_timeout. Self-contained under mktemp; macOS + ubuntu CI safe. +set -uo pipefail +ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" +. "$ROOT/qa/lib_beat_driver.sh" + +TMP="$(mktemp -d)"; trap 'rm -rf "$TMP"' EXIT +STATE_DIR="$TMP/state"; mkdir -p "$STATE_DIR" +T="$TMP"; RUN="r"; COMBINED="$TMP/combined.jsonl"; : > "$COMBINED" +DM_CFG="$TMP/dm.json"; : > "$DM_CFG" +CLAWDND_DM_MODEL="sonnet"; BUDGET="1.50"; CLAWDND_LEAN_TAIL=8 + +fail=0 +chk() { if eval "$2"; then echo "PASS: $1"; else echo "FAIL: $1"; fail=1; fi; } + +# ---- VERBATIM: run_duo.sh turn() DM branch (F12-11 timeout-wrapped + failure-surfaced) --------- +# $1=first $2=msg ; sinks reproduced. Echoes $out path via DM_OUT so the argv probe can read it. +DM_OUT="" +duo_dm_turn() { + local first="$1" msg="$2" resume=() extra=() rc=0 out beat_timeout + [ "$first" = "0" ] && resume=(--resume "DSID") || resume=(--session-id "DSID") + clawdnd_dm_effort_arg "$first" + out="$T/$RUN.dm.$(date +%s%N).jsonl" + beat_timeout="$(clawdnd_dm_timeout "$first")" + worldos_timeout "$beat_timeout" \ + claude -p "$msg" ${resume[@]+"${resume[@]}"} ${extra[@]+"${extra[@]}"} --plugin-dir "$ROOT" --mcp-config "$DM_CFG" --strict-mcp-config \ + --model "$CLAWDND_DM_MODEL" ${CLAWDND_DM_EFFORT[@]+"${CLAWDND_DM_EFFORT[@]}"} --permission-mode bypassPermissions --max-budget-usd "$BUDGET" \ + --output-format stream-json --verbose > "$out" 2>> "$T/$RUN.dm.err" + rc=$? + DM_OUT="$out" + cat "$out" >> "$COMBINED" + if [ "$rc" -ne 0 ] && ! clawdnd_dm_result_is_error "$out"; then + clawdnd_report_attempt_failure "$out" "$rc" + fi + clawdnd_dm_final_text "$out" "$STATE_DIR" "$rc" +} + +# (1) argv capture: the DM cold open IS wrapped in worldos_timeout with the sonnet cold-open 550. +claude() { printf 'CLAUDE-ARGV-BEGIN\n'; local a; for a in "$@"; do printf ' «%s»\n' "$a"; done; printf 'CLAUDE-ARGV-END\n'; } +worldos_timeout() { printf 'TIMEOUT-WRAP «%s»\n' "$1"; shift; "$@"; } +duo_dm_turn 1 'Begin the session.' >/dev/null; argv_co="$(cat "$DM_OUT")" +chk "duo DM cold open IS worldos_timeout-wrapped" 'printf "%s" "$argv_co" | grep -q -- "TIMEOUT-WRAP"' +chk "duo DM cold open deadline is the 550 tier" 'printf "%s" "$argv_co" | grep -q -- "TIMEOUT-WRAP «550»"' +duo_dm_turn 0 'Resolve the move.' >/dev/null; argv_rt="$(cat "$DM_OUT")" +chk "duo DM routine beat deadline is the 360 tier" 'printf "%s" "$argv_rt" | grep -q -- "TIMEOUT-WRAP «360»"' +unset -f claude worldos_timeout +. "$ROOT/qa/lib_beat_driver.sh" # restore the real worldos_timeout shim for the behavior probes below +# worldos_timeout execs `claude` as an EXTERNAL command (timeout(1) or a python3 subprocess), neither +# of which can see a bash FUNCTION — so the behavior probes use real stub EXECUTABLES on PATH. +BIN="$TMP/bin"; mkdir -p "$BIN"; PATH="$BIN:$PATH" + +# (2a) a 401 error-class RESULT (rc=0) → clawdnd_dm_final_text echoes EMPTY and surfaces the 401 hint. +cat > "$BIN/claude" <<'STUB' +#!/usr/bin/env bash +printf '%s\n' '{"type":"result","subtype":"error_during_execution","is_error":true,"api_error_status":401,"result":"API Error: 401 authentication_error"}' +exit 0 +STUB +chmod +x "$BIN/claude" +reply401="$(duo_dm_turn 0 'Resolve.' 2>"$TMP/err401")" +chk "401 result → DM reply text is EMPTY (not chatted as prose)" '[ -z "$reply401" ]' +chk "401 result → real cause surfaced on stderr" 'grep -q "dm-attempt" "$TMP/err401"' +chk "401 result → flagged NOT retryable (re-auth hint)" 'grep -q "NOT retryable" "$TMP/err401"' +chk "401 result → names HTTP 401" 'grep -q "401" "$TMP/err401"' + +# (2b) a TIMEOUT (rc=124, no result event) → empty reply AND the timeout cause surfaced on stderr. +cat > "$BIN/claude" <<'STUB' +#!/usr/bin/env bash +sleep 600 +STUB +chmod +x "$BIN/claude" +start=$SECONDS +reply_to="$(WORLDOS_COLDOPEN_TIMEOUT=2 CLAWDND_BEAT_TIMEOUT=2 duo_dm_turn 0 'Resolve.' 2>"$TMP/errto")" +elapsed=$((SECONDS - start)) +chk "timeout → DM reply text is EMPTY" '[ -z "$reply_to" ]' +chk "timeout → killed at the deadline (<=10s, not 600s)" '[ "$elapsed" -le 10 ]' +chk "timeout → cause surfaced on stderr (dm-attempt)" 'grep -q "dm-attempt" "$TMP/errto"' + +# (3) the shared cold-open remint yields a FRESH --session-id (not the consumed one). +unset -f claude +CLAWDND_DM_RETRY_SESSION=() +clawdnd_dm_remint_session_on_retry --session-id "DSID-consumed-0000" +chk "shared remint emits a 2-token --session-id array" '[ "${#CLAWDND_DM_RETRY_SESSION[@]}" -ge 2 ]' +chk "shared remint mode is --session-id" '[ "${CLAWDND_DM_RETRY_SESSION[0]}" = "--session-id" ]' +chk "shared remint id is FRESH (not the consumed id)" '[ "${CLAWDND_DM_RETRY_SESSION[1]}" != "DSID-consumed-0000" ]' +chk "shared remint id is non-empty" '[ -n "${CLAWDND_DM_RETRY_SESSION[1]}" ]' + +[ "$fail" = 0 ] && echo "ALL ASSERTIONS PASSED" || echo "SOME ASSERTIONS FAILED" +exit "$fail" diff --git a/scripts/play.sh b/scripts/play.sh index 1850170b..8f6aced4 100755 --- a/scripts/play.sh +++ b/scripts/play.sh @@ -50,6 +50,18 @@ PORT_EXPLICIT=0 if declare -F clawdnd_choose_port >/dev/null 2>&1; then PORT="$(clawdnd_choose_port "$PORT" "$PORT_EXPLICIT")" || exit 1 fi +# F12-13 (audit 2026-06-11): single-flight launch lock — refuse a SECOND concurrent solo cold-open +# from this checkout so two play.sh runs can't collide on session ids / the viewer port (the +# "Session ID already in use" failure observed under memory pressure on the 16GB host). play_party.sh +# has carried this lock since its ensemble landed, BUT it acquires AFTER `exec play.sh` on the solo +# path — so a solo launch (the .app's default) previously had NO lock and two solo launches stacked +# two viewers + two DM sessions. Acquired here, before any heavy work (the hero pre-seed mints a +# campaign, the viewer supervisor, the DSID mint, the DM cold-open); released in _play_cleanup below. +# A rejected launch exits HERE, before the EXIT/INT/TERM traps are armed, so it runs no cleanup and +# never touches the holder's lock. (set -uo pipefail has no -e, so the explicit `exit 1` is required.) +if declare -F clawdnd_acquire_launch_lock >/dev/null 2>&1; then + clawdnd_acquire_launch_lock "$ROOT" || exit 1 +fi # The DM model is an env var (default opus, owner 2026-06-06) — one-flag flip; mirrors qa/run_duo.sh. CLAWDND_DM_MODEL="$(worldos_env DM_MODEL opus)" # Budgets scale to the DM model: an Opus turn — especially the max-effort cold-open world-build — @@ -112,6 +124,12 @@ CHAT="$STATE_DIR/chat.jsonl"; : > "$CHAT" DM_LOG="$STATE_DIR/dm" # per-turn stream-json files: $DM_LOG..jsonl COMBINED="$STATE_DIR/dm.combined.jsonl"; : > "$COMBINED" VIEWER_LOG="$STATE_DIR/viewer.log" +# F12-10: the provider-status sidecar path is defined HERE (before the traps are armed) so an EARLY +# abort — a dead cold open that exits before the loop — still leaves a "failed" sidecar for the viewer +# to bucket as no_provider, instead of the live-looking "unknown" fallback. The actual writes happen +# below: "running" once seated, "stopped" on a clean cap/budget stop, "failed" in the EXIT trap. +PROVIDER_STATUS="$STATE_DIR/provider_status.json" +PROVIDER_STOPPED_CLEANLY=0 # Wire the three plugin MCP servers (engine/rules/voice) from THIS repo, with the # engine pointed at this game's state dir and a silent voice backend (the dashboard @@ -376,7 +394,20 @@ viewer_supervisor & SUP=$! # paced loop below has no idle ceiling, so it would spin `sleep 2` forever). Separate the EXIT trap # (cleanup) from the signal traps (cleanup + exit) so a normal `kill` actually stops it. (Mirrors # play_party.sh.) -_play_cleanup() { kill "$SUP" 2>/dev/null; [ -f "$VPID_FILE" ] && kill "$(cat "$VPID_FILE" 2>/dev/null)" 2>/dev/null; } +# F12-10: on an ABNORMAL exit (a crash, a kill -TERM, an early cold-open abort) write the "failed" +# provider-status sidecar so the viewer buckets it as no_provider — BUT never overwrite a clean +# "stopped" (cap/budget) row, and only when the path is already known (set near STATE_DIR). Guarded +# for set -u (the early aborts run before some globals exist). Written BEFORE the viewer is killed so +# the row lands while a read could still serve it. +_play_cleanup() { + if [ "${PROVIDER_STOPPED_CLEANLY:-0}" != "1" ] && [ -n "${PROVIDER_STATUS:-}" ] \ + && declare -F clawdnd_write_provider_status >/dev/null 2>&1; then + clawdnd_write_provider_status "$PROVIDER_STATUS" failed crashed "ClawDnD DM provider exited unexpectedly. Restart the session to continue." "${DM_TURNS:-0}" "scripts/play.sh" + fi + declare -F clawdnd_release_launch_lock >/dev/null 2>&1 && clawdnd_release_launch_lock "$ROOT" + kill "$SUP" 2>/dev/null + [ -f "$VPID_FILE" ] && kill "$(cat "$VPID_FILE" 2>/dev/null)" 2>/dev/null +} trap _play_cleanup EXIT trap '_play_cleanup; exit 130' INT TERM @@ -510,23 +541,57 @@ if ! clawdnd_pc_seated "$STATE_DIR" "$CAMPAIGN_ID"; then echo "[play] reseat OK — a player PC is now seated in the party." fi +# F12-10 (audit 2026-06-11): the provider-status sidecar the viewer reads. The CLAUDE lane never wrote +# it (only the codex wrapper did), so on a turn-cap/budget stop or a crash the viewer fell back to +# "unknown" and showed a live-looking-but-dead dashboard instead of the "DM provider is no longer +# running" surface. Write it through the SHARED clawdnd_write_provider_status (qa/lib_beat_driver.sh): +# "running" now (the session is playable — the seating guard above passed), "stopped" on a clean cap/ +# budget stop, "failed" on an abnormal exit (the EXIT trap below). The sidecar is derived/atomic state, +# not campaign state, so the engine stays the sole writer. A local thin wrapper passes $DM_TURNS +# (PROVIDER_STATUS + PROVIDER_STOPPED_CLEANLY were defined near STATE_DIR so an early-abort EXIT trap +# can write "failed"). +provider_status_set() { clawdnd_write_provider_status "$PROVIDER_STATUS" "$1" "$2" "$3" "$DM_TURNS" "scripts/play.sh"; } +provider_status_set running active "ClawDnD DM provider is running." + # Stop the (otherwise human-paced, unbounded) loop once the session hits its cost or turn # ceiling. total_cost_usd is reported on each turn's result event (accumulated in $COMBINED). +# F12-10: a clean stop writes the "stopped" sidecar (with the reason) + a short grace window so the +# viewer can render the "provider stopped" surface BEFORE the EXIT trap kills it, then sets the +# clean-stop flag so the EXIT trap does NOT overwrite "stopped" with "failed". over_budget() { local spent; spent="$(jq -rs '[.[]|select(.type=="result")|.total_cost_usd//0]|add // 0' "$COMBINED" 2>/dev/null)" - [ "$DM_TURNS" -ge "$MAX_TURNS" ] && { echo "[play] turn cap ($MAX_TURNS) reached — stopping (raise CLAWDND_PLAY_MAX_TURNS)."; return 0; } - awk -v s="${spent:-0}" -v b="$SESSION_BUDGET" 'BEGIN{exit !(s+0>=b+0)}' \ - && { echo "[play] session budget reached (~\$$spent/\$$SESSION_BUDGET) — stopping (raise CLAWDND_PLAY_SESSION_BUDGET)."; return 0; } + if [ "$DM_TURNS" -ge "$MAX_TURNS" ]; then + echo "[play] turn cap ($MAX_TURNS) reached — stopping (raise CLAWDND_PLAY_MAX_TURNS)." + provider_status_set stopped turn_cap "ClawDnD DM stopped after reaching the configured max turns. Increase Max turns or start a new session to continue." + PROVIDER_STOPPED_CLEANLY=1 + sleep "${WORLDOS_PROVIDER_STOP_GRACE_SECONDS:-${CLAWDND_PROVIDER_STOP_GRACE_SECONDS:-20}}" + return 0 + fi + if awk -v s="${spent:-0}" -v b="$SESSION_BUDGET" 'BEGIN{exit !(s+0>=b+0)}'; then + echo "[play] session budget reached (~\$$spent/\$$SESSION_BUDGET) — stopping (raise CLAWDND_PLAY_SESSION_BUDGET)." + provider_status_set stopped budget "ClawDnD DM stopped after reaching the session budget (~\$$spent/\$$SESSION_BUDGET). Raise CLAWDND_PLAY_SESSION_BUDGET or start a new session." + PROVIDER_STOPPED_CLEANLY=1 + sleep "${WORLDOS_PROVIDER_STOP_GRACE_SECONDS:-${CLAWDND_PROVIDER_STOP_GRACE_SECONDS:-20}}" + return 0 + fi return 1 } # Human-paced loop: when a new move lands in $MOVES (you acted in the dashboard), resolve # it with a DM turn and render the next beat. Otherwise idle, waiting on your next move. MCURSOR="$(wc -l < "$MOVES" 2>/dev/null | tr -d ' ')"; MCURSOR="${MCURSOR:-0}" +# F12-13 (audit 2026-06-11): IDLE CEILING. This loop waits for a HUMAN move in $MOVES. With no human +# acting (a dry-run, or a player who walked away) it would otherwise spin `sleep 2` FOREVER — the same +# orphan class play_party.sh added CLAWDND_PLAY_MAX_IDLE for after an 8.5h orphan, but play.sh (the .app's +# DEFAULT solo entry point) never got it. Stop after CLAWDND_PLAY_MAX_IDLE seconds (default 30 min) with +# no new move; relaunch when ready. Same knob + default as play_party.sh (WORLDOS_/CLAWDND_ twin). +MAX_IDLE="${WORLDOS_PLAY_MAX_IDLE:-${CLAWDND_PLAY_MAX_IDLE:-1800}}" +last_activity=$SECONDS while true; do over_budget && break total="$(wc -l < "$MOVES" 2>/dev/null | tr -d ' ')"; total="${total:-0}" if [ "$total" -gt "$MCURSOR" ]; then + last_activity=$SECONDS new="$(tail -n +"$((MCURSOR + 1))" "$MOVES" 2>/dev/null)"; MCURSOR="$total" # The dashboard palette sends {kind,name}; Say/Do send {kind,text}. The Seed screen sends # {kind:"set_seed_param",param,value[,force]} (#266) — render it as a config directive @@ -570,6 +635,15 @@ $RUNBOOK" "$CAMPAIGN_ID")" # clock frozen this beat (engine stays the sole writer; defers to the DM's in-fiction pacing). clawdnd_soft_tick "$ROOT" "$STATE_DIR" "$PREV_DAY" "$PREV_TOD" else + # F12-13: idle ceiling — stop a player-less session instead of spinning `sleep 2` forever. + if [ $((SECONDS - last_activity)) -ge "$MAX_IDLE" ]; then + echo "[play] idle ${MAX_IDLE}s with no player move — stopping (relaunch when ready; raise CLAWDND_PLAY_MAX_IDLE to wait longer)." + # F12-10: an idle stop is a CLEAN stop (not a crash) — write "stopped"/idle, set the flag so the + # EXIT trap does not relabel it "failed". + provider_status_set stopped idle "ClawDnD DM stopped after ${MAX_IDLE}s with no player move. Relaunch to continue (raise CLAWDND_PLAY_MAX_IDLE to wait longer)." + PROVIDER_STOPPED_CLEANLY=1 + break + fi sleep 2 fi done diff --git a/scripts/play_codex_dm.sh b/scripts/play_codex_dm.sh index 7d7a1b71..e3e82ca4 100755 --- a/scripts/play_codex_dm.sh +++ b/scripts/play_codex_dm.sh @@ -625,12 +625,106 @@ record_dm_reply() { fi } -codex_dm_turn() { - local prompt="$1" - printf '%s\n' "$prompt" > "$PROMPT_FILE" - : > "$LAST_MESSAGE" - local status=0 - codex exec \ +# F12-9: bounded-command shim, behaviorally identical to qa/lib_beat_driver.sh's worldos_timeout (the +# canonical copy). This wrapper is deliberately self-contained (it owns its own chatlog / +# write_provider_status / log_engine_narration and does NOT source the beat-driver lib), so it carries +# a local copy here rather than pull in ~35 lib helpers + 3 name clashes. timeout(1) when present +# (cheapest), else a python3 subprocess preserving rc=124 (deadline) / 127 (not found) / 126 (not +# exec). The F12-20 consolidation finding tracks deduping this against the lib copy. $1=secs $2..=cmd. +worldos_timeout() { + local _secs="$1"; shift + if command -v timeout >/dev/null 2>&1; then + timeout "$_secs" "$@" + return $? + fi + python3 -c ' +import subprocess, sys +secs = float(sys.argv[1]) +cmd = sys.argv[2:] +try: + sys.exit(subprocess.run(cmd, timeout=secs).returncode) +except subprocess.TimeoutExpired: + sys.exit(124) +except FileNotFoundError: + sys.exit(127) +except PermissionError: + sys.exit(126) +except KeyboardInterrupt: + sys.exit(130) +' "$_secs" "$@" +} + +# F12-9: estimate the session's USD spend from codex's cumulative token usage. Codex `exec --json` +# emits token_count events; we take the LARGEST cumulative total seen across all turns in $STDOUT_LOG +# (the events report a running total) and convert at WORLDOS_CODEX_USD_PER_MTOK (USD per MILLION +# tokens — an explicit, overridable BLENDED rate; default a conservative gpt-5.x estimate). Echoes the +# estimate as a decimal, or 0 when nothing is parseable (so the turn cap stays the hard ceiling). +# Read-only; jq-optional (a python fallback parses the same fields). No engine state touched. +codex_session_spend_usd() { + local rate="${WORLDOS_CODEX_USD_PER_MTOK:-${CLAWDND_CODEX_USD_PER_MTOK:-10}}" + [ -f "$STDOUT_LOG" ] || { printf '0'; return 0; } + python3 - "$STDOUT_LOG" "$rate" 2>/dev/null <<'PY' || printf '0' +import json, sys +path, rate = sys.argv[1], float(sys.argv[2]) +best = 0 +def total_from(obj): + # Accept several shapes codex has used for cumulative usage. + if not isinstance(obj, dict): + return None + for key in ("total_token_usage", "token_usage", "usage", "info"): + v = obj.get(key) + if isinstance(v, dict): + t = total_from(v) + if t is not None: + return t + tot = obj.get("total_tokens") + if isinstance(tot, (int, float)): + return tot + parts = [obj.get(k) for k in ("input_tokens", "output_tokens", "cached_input_tokens", "reasoning_output_tokens")] + nums = [p for p in parts if isinstance(p, (int, float))] + if nums: + return sum(nums) + return None +try: + with open(path, encoding="utf-8") as fh: + for line in fh: + line = line.strip() + if not line: + continue + try: + ev = json.loads(line) + except ValueError: + continue + t = total_from(ev) + if t is not None and t > best: + best = t +except OSError: + pass +print("%.6f" % (best / 1_000_000.0 * rate)) +PY +} + +# F12-9: stop the session "exhausted" when the estimated spend crosses CLAWDND_PLAY_SESSION_BUDGET. +# Called AFTER each completed turn (spend only changes then). Sets BUDGET_EXCEEDED=1 + PROVIDER_ +# STOPPED_CLEANLY=1 and stamps the sidecar; the loop honors BUDGET_EXCEEDED at the top and breaks. +# Best-effort: an unparseable token stream leaves the estimate 0, so the turn cap stays the ceiling. +enforce_session_budget() { + local spent; spent="$(codex_session_spend_usd)" + if awk -v s="${spent:-0}" -v b="$CLAWDND_PLAY_SESSION_BUDGET" 'BEGIN{exit !(s+0>=b+0)}'; then + write_provider_status "exhausted" "budget" "Codex DM stopped after reaching the session budget (~\$$spent/\$$CLAWDND_PLAY_SESSION_BUDGET). Raise CLAWDND_PLAY_SESSION_BUDGET or start a new provider-backed session." + BUDGET_EXCEEDED=1 + PROVIDER_STOPPED_CLEANLY=1 + fi +} + +# One `codex exec` attempt, BOUNDED by worldos_timeout (F12-8/F12-9). A wedged codex turn (hung MCP +# startup, a stuck model call) previously ran UNBOUNDED — it could hang the session indefinitely. +# WORLDOS_CODEX_TURN_TIMEOUT (default 500s — codex max-effort cold opens run long, parity with the +# claude cold-open tier) caps it; rc=124 on a timeout. Writes the last message to $LAST_MESSAGE and +# tees the JSON stream to $STDOUT_LOG (so codex_session_spend_usd can read cumulative token usage). +_codex_exec_once() { + worldos_timeout "${WORLDOS_CODEX_TURN_TIMEOUT:-${CLAWDND_CODEX_TURN_TIMEOUT:-500}}" \ + codex exec \ --sandbox read-only \ --json \ ${MODEL_ARGS[@]+"${MODEL_ARGS[@]}"} \ @@ -653,7 +747,26 @@ codex_dm_turn() { -c "mcp_servers.clawdnd-voice.default_tools_approval_mode=\"approve\"" \ - < "$PROMPT_FILE" \ > >(tee -a "$STDOUT_LOG" >/dev/null) \ - 2> >(tee -a "$STDERR_LOG" >&2) || status=$? + 2> >(tee -a "$STDERR_LOG" >&2) +} + +codex_dm_turn() { + local prompt="$1" + printf '%s\n' "$prompt" > "$PROMPT_FILE" + : > "$LAST_MESSAGE" + # F12-9: ONE retry. Each `codex exec` is a STATELESS fresh invocation (no --session-id to collide, + # unlike the claude --resume path), so a retry is session-safe — a transient timeout / CLI blip / + # rate bump that killed attempt 1 gets a second chance instead of a hard `fail` that left the + # sidecar stuck "running". The prompt file is reused; $LAST_MESSAGE is re-truncated per attempt so a + # partial first message can't leak into the retry's reply. + local status=0 + _codex_exec_once || status=$? + if [ "$status" -ne 0 ]; then + echo "[codex-dm-provider] codex turn rc=$status — retrying once (codex turns are stateless, so the retry is session-safe)" >&2 + : > "$LAST_MESSAGE" + status=0 + _codex_exec_once || status=$? + fi [ "$status" -eq 0 ] || return "$status" local last @@ -711,7 +824,20 @@ viewer_supervisor() { done } viewer_supervisor & SUP=$! +# F12-9 (audit 2026-06-11): the EXIT/INT/TERM trap previously killed only SUP + the viewer — it never +# wrote the provider-status sidecar, so a CRASH (a codex auth failure, an OOM, a kill -TERM) left the +# sidecar stuck at "running" and the viewer kept showing a live-looking-but-dead dashboard (the +# {stopped,failed,exhausted} set is what the viewer buckets as no_provider). Now the trap stamps +# "failed" on an ABNORMAL exit — UNLESS the run already stopped cleanly (turn cap / budget), which +# sets PROVIDER_STOPPED_CLEANLY=1 so the trap never relabels a clean "stopped" as "failed". Written +# BEFORE the viewer is killed so the row lands while a read could still serve it. DM_TURNS is a global. +PROVIDER_STOPPED_CLEANLY=0 +BUDGET_EXCEEDED=0 +DM_TURNS=0 _cleanup() { + if [ "${PROVIDER_STOPPED_CLEANLY:-0}" != "1" ]; then + write_provider_status "failed" "crashed" "Codex DM provider exited unexpectedly. Restart the provider-backed session to continue." 2>/dev/null || true + fi kill "$SUP" 2>/dev/null || true [ -f "$VPID_FILE" ] && kill "$(cat "$VPID_FILE" 2>/dev/null)" 2>/dev/null || true } @@ -721,7 +847,6 @@ trap '_cleanup; exit 130' INT TERM echo "WorldOS Codex DM provider -> $VIEWER_URL" echo " Save dir: $RUN_DIR" -DM_TURNS=0 write_provider_status "running" "active" "Codex DM provider is running." MCURSOR="$(wc -l < "$MOVES" 2>/dev/null | tr -d ' ')" @@ -804,12 +929,18 @@ CAMPAIGN_TOOL_HINT="$(campaign_tool_hint "$ACTIVE_CAMPAIGN_ID")" DM_TURNS=1 write_provider_status "running" "active" "Codex DM provider is running." +enforce_session_budget # F12-9: the opening world-build can itself exhaust a tiny session budget. while true; do if [ "$DM_TURNS" -ge "$CLAWDND_PLAY_MAX_TURNS" ]; then write_provider_status "stopped" "turn_cap" "Codex DM stopped after reaching the configured max turns. Increase Max turns or start a new provider-backed session to continue." + PROVIDER_STOPPED_CLEANLY=1 # F12-9: a clean stop — the EXIT trap must not relabel it "failed". sleep "${WORLDOS_PROVIDER_STOP_GRACE_SECONDS:-${CLAWDND_PROVIDER_STOP_GRACE_SECONDS:-20}}" break fi + # F12-9: budget enforcement is checked AFTER each completed turn (enforce_session_budget), not here + # on every idle poll — spend only changes when a turn runs, so polling spend every 2s would spawn a + # python3 estimate needlessly. The post-turn check below sets BUDGET_EXCEEDED=1; honor it at the top. + if [ "${BUDGET_EXCEEDED:-0}" = "1" ]; then break; fi total="$(wc -l < "$MOVES" 2>/dev/null | tr -d ' ')" total="${total:-0}" if [ "$total" -gt "$MCURSOR" ]; then @@ -848,6 +979,7 @@ $PMSG")"; then record_dm_reply "$ACTIVE_CAMPAIGN_ID" "$REPLY" "move" DM_TURNS=$((DM_TURNS + 1)) write_provider_status "running" "active" "Codex DM provider is running." + enforce_session_budget # F12-9: check spend AFTER the turn that changed it (loop honors it next iter). else sleep 2 fi diff --git a/scripts/play_party.sh b/scripts/play_party.sh index 39c57eea..b253bd9a 100755 --- a/scripts/play_party.sh +++ b/scripts/play_party.sh @@ -148,6 +148,12 @@ CHAT="$STATE_DIR/chat.jsonl"; : > "$CHAT" DM_LOG="$STATE_DIR/dm" # per-turn stream-json files: $DM_LOG..jsonl COMBINED="$STATE_DIR/dm.combined.jsonl"; : > "$COMBINED" # every agent turn's stream (cost accounting) VIEWER_LOG="$STATE_DIR/viewer.log" +# F12-10 (audit 2026-06-11): the provider-status sidecar the viewer reads — the CLAUDE lanes never +# wrote it, so a cap/budget stop or crash showed a live-looking dead dashboard. Path defined HERE +# (before the traps) so an early-abort EXIT trap can write "failed". Writes below: "running" once +# seated, "stopped" on a clean cap/budget/idle stop, "failed" on an abnormal exit. (Same as play.sh.) +PROVIDER_STATUS="$STATE_DIR/provider_status.json" +PROVIDER_STOPPED_CLEANLY=0 # #623: the live-progress rule (parity with scripts/play_codex_dm.sh's LIVE_PROGRESS_LOG_RULE). # Without it the claude/plugin DM emits NOTHING to /events until the full 85-157s beat completes, @@ -371,9 +377,21 @@ turn() { clawdnd_dm_final_text "$out" "$STATE_DIR" "$rc" else out="$STATE_DIR/companion.$(date +%s%N).jsonl" - claude -p "$msg" "${resume[@]}" --mcp-config "$cfg" --strict-mcp-config \ - --model "$CLAWDND_ACTOR_MODEL" --permission-mode bypassPermissions --max-budget-usd "$BUDGET" \ - --output-format stream-json --verbose > "$out" 2>> "$STATE_DIR/companion.err" + # F12-12 (audit 2026-06-11): the companion facade turn was a BARE `claude -p` with NO per-beat + # deadline, so a wedged companion (hung MCP startup, a stuck model call) blocked companion_moves + # — which runs BEFORE the DM turn each beat — indefinitely: the human's move was acknowledged and + # the cursor advanced, but nothing ever resolved. Bound it through the SAME worldos_timeout shim + # the DM turn uses (timeout(1) when present, else the python3 rc=124 fallback), at + # WORLDOS_ACTOR_TIMEOUT (default 120s — a companion facade move is a single tool-driven turn, far + # shorter than a DM beat). On a timeout (or any nonzero rc) the partial $out yields no result + # event, so the jq below echoes empty and companion_moves skips this companion's move for the beat + # (its `[ -n "$cm" ] &&` guard) — graceful degradation: the beat still reaches the DM. The + # companion is NOT retried (unlike the DM): a missed companion move is recoverable next beat, and a + # retry would double its latency ahead of the DM. Cost still accrues via $COMBINED on whatever ran. + worldos_timeout "${WORLDOS_ACTOR_TIMEOUT:-${CLAWDND_ACTOR_TIMEOUT:-120}}" \ + claude -p "$msg" "${resume[@]}" --mcp-config "$cfg" --strict-mcp-config \ + --model "$CLAWDND_ACTOR_MODEL" --permission-mode bypassPermissions --max-budget-usd "$BUDGET" \ + --output-format stream-json --verbose > "$out" 2>> "$STATE_DIR/companion.err" || true cat "$out" >> "$COMBINED" # companion tool-call cost counts toward the session ceiling jq -rs 'map(select(.type=="result"))[-1].result // ""' "$out" 2>/dev/null fi @@ -454,7 +472,19 @@ viewer_supervisor & SUP=$! # main loop, so `kill`/closing the window couldn't stop a wedged run (it took kill -9, and a # dry-run with no human spun a sleep-loop for 8.5h). Separate the EXIT trap (cleanup) from the # signal traps (cleanup + exit) so a normal `kill` actually stops it. -_party_cleanup() { declare -F clawdnd_release_launch_lock >/dev/null 2>&1 && clawdnd_release_launch_lock "$ROOT"; kill "$SUP" 2>/dev/null; [ -f "$VPID_FILE" ] && kill "$(cat "$VPID_FILE" 2>/dev/null)" 2>/dev/null; } +# F12-10: on an ABNORMAL exit (crash, kill -TERM, early cold-open abort) write "failed" so the viewer +# buckets it as no_provider — never overwriting a clean "stopped" (cap/budget/idle), and only when the +# path is already known. Guarded for set -u (early aborts run before some globals exist). Written +# BEFORE the viewer is killed so the row lands while a read could still serve it. +_party_cleanup() { + if [ "${PROVIDER_STOPPED_CLEANLY:-0}" != "1" ] && [ -n "${PROVIDER_STATUS:-}" ] \ + && declare -F clawdnd_write_provider_status >/dev/null 2>&1; then + clawdnd_write_provider_status "$PROVIDER_STATUS" failed crashed "ClawDnD DM provider exited unexpectedly. Restart the session to continue." "${AGENT_TURNS:-0}" "scripts/play_party.sh" + fi + declare -F clawdnd_release_launch_lock >/dev/null 2>&1 && clawdnd_release_launch_lock "$ROOT" + kill "$SUP" 2>/dev/null + [ -f "$VPID_FILE" ] && kill "$(cat "$VPID_FILE" 2>/dev/null)" 2>/dev/null +} trap _party_cleanup EXIT trap '_party_cleanup; exit 130' INT TERM @@ -582,13 +612,33 @@ Narrate the RESULT of each declared move (never invent a companion's internal ch [ -n "$DMSG" ] && { record_dm_reply "$CAMPAIGN_ID" "$DMSG" after_intros; AGENT_TURNS=$((AGENT_TURNS + 1)); echo "[play-party] DM after intros: ${DMSG:0:120}…"; } fi +# F12-10: the session is playable (the seating guard above passed) — write the "running" sidecar so +# the viewer shows a live provider. Shared writer; AGENT_TURNS is this lane's turn counter. (play.sh +# parity; the EXIT trap relabels it "failed" on a crash, over_budget/idle relabel "stopped".) +provider_status_set() { clawdnd_write_provider_status "$PROVIDER_STATUS" "$1" "$2" "$3" "$AGENT_TURNS" "scripts/play_party.sh"; } +provider_status_set running active "ClawDnD party DM provider is running." + # --- session ceiling (aggregate cost + turn cap), mirrors play.sh + run_party.sh -------- +# F12-10: a clean cap/budget stop writes the "stopped" sidecar (with the reason) + a short grace +# window so the viewer renders the "provider stopped" surface before the EXIT trap kills it, then sets +# the clean-stop flag so the EXIT trap does NOT relabel "stopped" as "failed". over_budget() { local spent - [ "$AGENT_TURNS" -ge "$MAX_TURNS" ] && { echo "[play-party] turn cap ($MAX_TURNS) reached — stopping (raise CLAWDND_PLAY_MAX_TURNS)."; return 0; } + if [ "$AGENT_TURNS" -ge "$MAX_TURNS" ]; then + echo "[play-party] turn cap ($MAX_TURNS) reached — stopping (raise CLAWDND_PLAY_MAX_TURNS)." + provider_status_set stopped turn_cap "ClawDnD party DM stopped after reaching the configured max turns. Increase Max turns or start a new session to continue." + PROVIDER_STOPPED_CLEANLY=1 + sleep "${WORLDOS_PROVIDER_STOP_GRACE_SECONDS:-${CLAWDND_PROVIDER_STOP_GRACE_SECONDS:-20}}" + return 0 + fi spent="$(jq -rs '[.[]|select(.type=="result")|.total_cost_usd//0]|add // 0' "$COMBINED" 2>/dev/null)" - awk -v s="${spent:-0}" -v b="$SESSION_BUDGET" 'BEGIN{exit !(s+0>=b+0)}' \ - && { echo "[play-party] session budget reached (~\$$spent/\$$SESSION_BUDGET) — stopping (raise CLAWDND_PLAY_SESSION_BUDGET)."; return 0; } + if awk -v s="${spent:-0}" -v b="$SESSION_BUDGET" 'BEGIN{exit !(s+0>=b+0)}'; then + echo "[play-party] session budget reached (~\$$spent/\$$SESSION_BUDGET) — stopping (raise CLAWDND_PLAY_SESSION_BUDGET)." + provider_status_set stopped budget "ClawDnD party DM stopped after reaching the session budget (~\$$spent/\$$SESSION_BUDGET). Raise CLAWDND_PLAY_SESSION_BUDGET or start a new session." + PROVIDER_STOPPED_CLEANLY=1 + sleep "${WORLDOS_PROVIDER_STOP_GRACE_SECONDS:-${CLAWDND_PROVIDER_STOP_GRACE_SECONDS:-20}}" + return 0 + fi return 1 } @@ -684,6 +734,9 @@ Then PLAY the next beat as a full lived scene — NOT a fragment: any NPC (or co else if [ $((SECONDS - last_activity)) -ge "$MAX_IDLE" ]; then echo "[play-party] idle ${MAX_IDLE}s with no player move — stopping (relaunch when ready; raise CLAWDND_PLAY_MAX_IDLE to wait longer)." + # F12-10: an idle stop is CLEAN (not a crash) — write "stopped"/idle + set the flag. + provider_status_set stopped idle "ClawDnD party DM stopped after ${MAX_IDLE}s with no player move. Relaunch to continue (raise CLAWDND_PLAY_MAX_IDLE to wait longer)." + PROVIDER_STOPPED_CLEANLY=1 break fi sleep 2 diff --git a/servers/engine/tests/test_codex_provider_wrapper.py b/servers/engine/tests/test_codex_provider_wrapper.py index 7c205d54..ecf838dc 100644 --- a/servers/engine/tests/test_codex_provider_wrapper.py +++ b/servers/engine/tests/test_codex_provider_wrapper.py @@ -584,3 +584,183 @@ def test_codex_wrappers_match_current_cli_flags(): assert "--sandbox read-only" in source assert 'default_tools_approval_mode=\\"approve\\"' in source assert "gpt-5.1-codex-max" not in source + + +# --- F12-9: codex DM wrapper hardening (timeout + retry, EXIT-failed status, budget enforcement) ---- + +def test_codex_dm_wrapper_bounds_codex_exec_with_one_retry(): + """The codex turn must be worldos_timeout-bounded with ONE session-safe retry (was unbounded).""" + source = DM_SCRIPT.read_text(encoding="utf-8") + assert "worldos_timeout()" in source # the inline F12-8 shim is present + assert "WORLDOS_CODEX_TURN_TIMEOUT" in source # the codex turn deadline knob + assert "worldos_timeout" in source and "codex exec" in source + # the shim wraps the codex invocation + exec_start = source.index("_codex_exec_once() {") + exec_block = source[exec_start : source.index("\n}", exec_start)] + assert "worldos_timeout" in exec_block + assert "codex exec" in exec_block + # ONE retry, documented as session-safe (stateless codex turns) + turn_start = source.index("codex_dm_turn() {") + turn_block = source[turn_start : source.index("LOG_EVENT_TOOL_RULE=", turn_start)] + assert turn_block.count("_codex_exec_once") >= 2 # attempt 1 + the retry + assert "retrying once" in turn_block + assert "stateless" in turn_block + + +def test_codex_dm_wrapper_marks_failed_on_abnormal_exit(): + """The EXIT/INT/TERM trap must stamp provider_status 'failed' on a crash (was stuck 'running').""" + source = DM_SCRIPT.read_text(encoding="utf-8") + cleanup_start = source.index("_cleanup() {") + cleanup_block = source[cleanup_start : source.index("trap _cleanup EXIT", cleanup_start)] + assert 'write_provider_status "failed"' in cleanup_block + assert "PROVIDER_STOPPED_CLEANLY" in cleanup_block + # a clean turn-cap / budget stop sets the flag so the trap does NOT relabel it + assert source.count("PROVIDER_STOPPED_CLEANLY=1") >= 2 + + +def test_codex_dm_wrapper_enforces_session_budget(): + """The budget envs were validated then never used — now the session budget is a hard stop.""" + source = DM_SCRIPT.read_text(encoding="utf-8") + assert "codex_session_spend_usd()" in source + assert "enforce_session_budget()" in source + assert "WORLDOS_CODEX_USD_PER_MTOK" in source + assert 'write_provider_status "exhausted"' in source + assert "CLAWDND_PLAY_SESSION_BUDGET" in source + # the spend check actually gates the loop (sets BUDGET_EXCEEDED, honored at the loop top) + assert "BUDGET_EXCEEDED" in source + # checked AFTER turns (opening + each move), not on every idle poll + assert source.count("enforce_session_budget") >= 3 + + +def test_codex_dm_wrapper_run_marks_failed_when_codex_crashes(tmp_path): + """A codex that always exits nonzero (after the retry) must end with provider_status 'failed'.""" + bin_dir = tmp_path / "bin" + bin_dir.mkdir() + fake_codex = bin_dir / "codex" + fake_codex.write_text( + """#!/usr/bin/env bash +# Consume stdin, write NOTHING to --output-last-message, exit nonzero — every attempt fails. +last="" +while [ "$#" -gt 0 ]; do + case "$1" in + --output-last-message) last="$2"; shift 2 ;; + *) shift ;; + esac +done +cat >/dev/null +exit 1 +""", + encoding="utf-8", + ) + fake_codex.chmod(0o755) + env = _env( + tmp_path, + PATH=f"{bin_dir}:{os.environ.get('PATH', '')}", + CLAWDND_RUN_ID="codex-crash", + CLAWDND_PLAY_PORT="8801", + CLAWDND_PLAY_HERO=json.dumps({"canon": True, "name": "Abby"}), + ) + result = _run_dm([], env, timeout=30) + + # The wrapper `fail`s the opening turn (rc=2), and the EXIT trap stamps the sidecar "failed". + assert result.returncode != 0, result.stdout + result.stderr + sidecar = tmp_path / "codex-crash" / "provider_status.json" + assert sidecar.exists(), result.stdout + result.stderr + payload = json.loads(sidecar.read_text(encoding="utf-8")) + assert payload["status"] == "failed" + # 'failed' is in the {stopped,failed,exhausted} set the viewer buckets as no_provider. + assert payload["status"] in {"stopped", "failed", "exhausted"} + + +def test_codex_dm_wrapper_run_retries_a_transient_failure(tmp_path): + """A codex that fails the FIRST attempt then succeeds must survive (the ONE retry recovers it).""" + bin_dir = tmp_path / "bin" + bin_dir.mkdir() + fake_codex = bin_dir / "codex" + # Fail once per logical turn, then succeed: a per-turn marker keyed off the prompt's turn nonce + # is overkill — instead use a global attempt counter file; the opening needs attempt 2 to pass. + fake_codex.write_text( + """#!/usr/bin/env bash +last="" +while [ "$#" -gt 0 ]; do + case "$1" in + --output-last-message) last="$2"; shift 2 ;; + *) shift ;; + esac +done +cat >/dev/null +ctr="$CLAWDND_STATE_DIR/.fake-attempts" +n=0; [ -f "$ctr" ] && n="$(cat "$ctr")"; n=$((n + 1)); printf '%s' "$n" > "$ctr" +# Fail the very first attempt (forces the retry), then succeed on every subsequent attempt. +if [ "$n" -eq 1 ]; then + exit 1 +fi +mkdir -p "$CLAWDND_STATE_DIR/campaigns/camp_fake" +printf '{"id":"camp_fake","active_session_id":"session_fake","characters":{"pc":{"kind":"player"}}}' > "$CLAWDND_STATE_DIR/campaigns/camp_fake/snapshot.json" +printf 'Opening narration after a retry.' > "$last" +printf '{"type":"result","result":"Opening narration after a retry."}\\n' +""", + encoding="utf-8", + ) + fake_codex.chmod(0o755) + env = _env( + tmp_path, + PATH=f"{bin_dir}:{os.environ.get('PATH', '')}", + CLAWDND_RUN_ID="codex-retry", + CLAWDND_PLAY_PORT="8802", + CLAWDND_PLAY_MAX_TURNS="1", + CLAWDND_PLAY_HERO=json.dumps({"canon": True, "name": "Abby"}), + ) + result = _run_dm([], env, timeout=30) + + assert result.returncode == 0, result.stdout + result.stderr + chat = (tmp_path / "codex-retry" / "chat.jsonl").read_text(encoding="utf-8") + assert "Opening narration after a retry." in chat + # turn cap (1) reached cleanly → 'stopped', NOT 'failed' (the retry recovered the opening). + payload = json.loads((tmp_path / "codex-retry" / "provider_status.json").read_text(encoding="utf-8")) + assert payload["status"] == "stopped" + assert payload["reason"] == "turn_cap" + + +def test_codex_dm_wrapper_run_stops_exhausted_over_session_budget(tmp_path): + """A codex that reports token usage over a tiny session budget must stop 'exhausted'.""" + bin_dir = tmp_path / "bin" + bin_dir.mkdir() + fake_codex = bin_dir / "codex" + # Seat a PC on the opening, emit a HUGE token_count event (cumulative), then succeed. With a tiny + # session budget the over-budget check fires BEFORE the next turn and stops 'exhausted'. + fake_codex.write_text( + """#!/usr/bin/env bash +last="" +while [ "$#" -gt 0 ]; do + case "$1" in + --output-last-message) last="$2"; shift 2 ;; + *) shift ;; + esac +done +cat >/dev/null +mkdir -p "$CLAWDND_STATE_DIR/campaigns/camp_fake" +printf '{"id":"camp_fake","active_session_id":"session_fake","characters":{"pc":{"kind":"player"}}}' > "$CLAWDND_STATE_DIR/campaigns/camp_fake/snapshot.json" +printf 'Opening narration with heavy token usage.' > "$last" +printf '{"type":"token_count","info":{"total_token_usage":{"input_tokens":4000000,"output_tokens":1000000}}}\\n' +printf '{"type":"result","result":"Opening narration with heavy token usage."}\\n' +""", + encoding="utf-8", + ) + fake_codex.chmod(0o755) + env = _env( + tmp_path, + PATH=f"{bin_dir}:{os.environ.get('PATH', '')}", + CLAWDND_RUN_ID="codex-budget", + CLAWDND_PLAY_PORT="8803", + CLAWDND_PLAY_MAX_TURNS="50", # high, so the BUDGET (not the turn cap) stops it + CLAWDND_PLAY_SESSION_BUDGET="0.10", # 5M tokens @ $10/Mtok = $50 >> $0.10 + WORLDOS_CODEX_USD_PER_MTOK="10", + CLAWDND_PLAY_HERO=json.dumps({"canon": True, "name": "Abby"}), + ) + result = _run_dm([], env, timeout=30) + + assert result.returncode == 0, result.stdout + result.stderr + payload = json.loads((tmp_path / "codex-budget" / "provider_status.json").read_text(encoding="utf-8")) + assert payload["status"] == "exhausted" + assert payload["reason"] == "budget" diff --git a/servers/engine/tests/test_opus_coldopen_tuning.py b/servers/engine/tests/test_opus_coldopen_tuning.py index 65da479d..ebc680c6 100644 --- a/servers/engine/tests/test_opus_coldopen_tuning.py +++ b/servers/engine/tests/test_opus_coldopen_tuning.py @@ -6,7 +6,12 @@ finishes ~300s WITH a full BG-caliber opening — "the lamps of Sorcerous Sundries burn low and blue…"). So the cold-open effort + deadline + the QA narration-wait are MODEL-AWARE: Opus gets high / 500s / -a longer narration grace; Sonnet is unchanged (max / 400s / the historic grace). +a longer narration grace; Sonnet keeps max / a longer narration grace. + +F12-2 (audit 2026-06-11): the NON-opus cold-open deadline was 400s — but a sonnet max-effort cold +open's OWN documented band is "~280–400s", so 400 == the band TOP (zero margin vs the band). Bumped to +550s so the sonnet A/B arm gets proportional margin to opus's. Opus is unchanged at 500s (still the +default DM model in every lane, so the shipped path is byte-identical). """ import unittest from pathlib import Path @@ -29,7 +34,10 @@ def test_coldopen_effort_is_high_for_opus(self): def test_coldopen_timeout_has_opus_margin(self): src = self._read("qa/lib_beat_driver.sh") - self.assertRegex(src, r"_co_timeout=400", "non-opus cold-open timeout stays 400s") + # F12-2: the non-opus default cleared its documented 400s band top — now 550s (margin over the + # band, not equal to it). Opus is unchanged at 500s. + self.assertRegex(src, r"_co_timeout=550", "non-opus cold-open timeout must clear the 400s band top (F12-2 -> 550s)") + self.assertNotRegex(src, r"_co_timeout=400", "the thin-margin 400s non-opus default must be gone (F12-2)") self.assertRegex(src, r"\*opus\*\)\s*_co_timeout=5\d\d", "Opus cold-open timeout must have margin (>=500s)") self.assertIn( 'worldos_env COLDOPEN_TIMEOUT "$_co_timeout"', src, diff --git a/servers/engine/tests/test_wrapper_reliability.py b/servers/engine/tests/test_wrapper_reliability.py index 9c19cc60..a53b9675 100644 --- a/servers/engine/tests/test_wrapper_reliability.py +++ b/servers/engine/tests/test_wrapper_reliability.py @@ -170,7 +170,7 @@ def test_routine_beat_timeout_env_override_still_wins(): def test_retry_timeout_escalates_to_the_coldopen_tier(): """Attempt 2 must NOT reuse attempt 1's deadline: it escalates to the model-aware cold-open - tier (opus 500 / default 400) and never DE-escalates below attempt 1's deadline.""" + tier (opus 500 / non-opus 550 after F12-2) and never DE-escalates below attempt 1's deadline.""" r = _bash( _CLEAN + 'CLAWDND_DM_MODEL=opus\n' @@ -182,7 +182,8 @@ def test_retry_timeout_escalates_to_the_coldopen_tier(): assert r.returncode == 0, r.stderr assert "opus360=500" in r.stdout, ("a routine retry escalates to the opus cold-open tier", r.stdout) assert "opus600=600" in r.stdout, ("never de-escalate below attempt 1's deadline", r.stdout) - assert "sonnet360=400" in r.stdout, ("non-opus escalates to the 400s cold-open tier", r.stdout) + # F12-2: the non-opus cold-open tier rose 400 -> 550, so a non-opus routine retry escalates to 550. + assert "sonnet360=550" in r.stdout, ("non-opus escalates to the 550s cold-open tier (F12-2)", r.stdout) def test_retry_timeout_tolerates_a_garbage_base():