diff --git a/qa/assert_behavioral.py b/qa/assert_behavioral.py index cd79af30..6302ab89 100644 --- a/qa/assert_behavioral.py +++ b/qa/assert_behavioral.py @@ -184,6 +184,23 @@ def chk(name: str, ok: bool, detail: str = "", fatal: bool = True) -> None: + ("" if has_companion else " (no companion in party ⇒ WARN not fatal)"), fatal=bool(has_companion)) + # SYN-01 (#757 leg 3): dead-beat honesty counters. The wrappers stamp dm rows with + # fallback_recovered:true (#357 prose recovered from the engine log, not the DM's own + # reply) and beat_failed:true (a wrapper-authored VISIBLE failure beat for a dead / + # error-class DM turn — qa/lib_beat_driver.sh clawdnd_chatlog_dm_failed). COUNT + REPORT + # both so a masked-dead run can never read as silently clean. The gate does NOT flip on + # them — the discount/gate policy stays #757's call; this is the consumer that policy + # was blocked on (the stamp was write-only: zero readers before this check). + recovered_rows = sum( + 1 for r in chat if r.get("role") == "dm" and r.get("fallback_recovered") is True) + failed_rows = sum( + 1 for r in chat if r.get("role") == "dm" and r.get("beat_failed") is True) + chk("dm_beat_honesty", failed_rows == 0 and recovered_rows == 0, + f"beats_failed={failed_rows} fallback_recovered={recovered_rows} — failed beats " + f"surfaced as visible failure rows (dead/error-class DM turns); recovered rows used " + f"the #357 engine-log fallback. Reported only; gate policy stays #757's call.", + fatal=False) + # 3.5) constrained-player (It.1 facade): the player must actually ACT through its # tools. An empty moves log means the facade was blocked/unused (e.g. a missing # --permission-mode), even though it may have produced complaint text. diff --git a/qa/dm_beat_mark.py b/qa/dm_beat_mark.py new file mode 100644 index 00000000..8f1a9ab4 --- /dev/null +++ b/qa/dm_beat_mark.py @@ -0,0 +1,178 @@ +#!/usr/bin/env python3 +"""Pre-beat session-log mark + post-beat NEW-prose check (SYN-01, issues #757/#745). + +The #357 empty-narration fallback (qa/dm_narration_fallback.py) recovers the engine-logged +prose when a DM turn ends with empty reply text. That recovery is GENUINE only when the DM +logged NEW player-facing prose THIS beat and then died before its final reply. When the beat +was fully dead, the only recoverable prose is the PREVIOUS beat's — recycling it masks the +dead beat as "resolved" (audit F12-14): the chat row dedups as already-logged, gets stamped +``engine_logged``, and the client hides it, so the player sees nothing while the harness +counts a resolved turn. + +This script is the discriminator: + + mark — BEFORE a DM beat's first attempt: record the active + session log file + its current line count (append-only, + so "lines past the mark" == "rows logged this beat"). + check — AFTER the beat: exit 0 iff at least one NEW player-facing + prose row (narration | dialogue; wrapper heartbeats and + setup-brief system-notation excluded — the exact filters + the #357 fallback itself applies) was logged past the + mark; exit 1 when everything recoverable predates the beat. + +FAIL-OPEN DISCIPLINE: this is best-effort plumbing on the beat path. A missing/corrupt mark, +an unreadable log, or ANY internal failure exits 0 ("assume genuine") so a broken checkout can +only ever degrade to today's pre-SYN-01 behavior — it must never fail a healthy recovery. + +Session-log resolution mirrors dm_narration_fallback._recover (active_session_id, else the +last session_ids entry, with the same bare-filename safety check); snapshot selection mirrors +clawdnd_snapshot_path in qa/lib_beat_driver.sh (the LARGEST non-empty snapshot). It lives as a +standalone file (not a heredoc inside ``$(...)``) because the macOS system bash 3.2 mis-parses +a quoted heredoc nested in command substitution — invoked by path from clawdnd_dm_prebeat_mark +/ clawdnd_dm_logged_new_prose in qa/lib_beat_driver.sh. +""" +import json +import os +import sys + +# Reuse the #357 fallback's own notion of "player-facing prose" (same dir, same python3) so +# the two can never drift; degrade to kind-filter-only on a broken checkout (fail-open: a +# wrapper line would then count as prose, which can only WIDEN "genuine" — never fail a beat). +try: + from dm_narration_fallback import ( + PROSE_KINDS, + _is_system_notation, + is_wrapper_progress_line, + ) +except Exception: # pragma: no cover - only on a broken checkout + PROSE_KINDS = {"narration", "dialogue"} + + def _is_system_notation(_text): + return False + + def is_wrapper_progress_line(_text): + return False + + +def _snapshot_path(state_dir): + """The LARGEST non-empty snapshot under /campaigns — mirrors the shell-side + clawdnd_snapshot_path (find -size +1c | ls -S | head -1).""" + best, best_size = "", 1 # >1 byte, matching find's -size +1c + root = os.path.join(state_dir, "campaigns") + try: + names = os.listdir(root) + except OSError: + return "" + for name in names: + p = os.path.join(root, name, "snapshot.json") + try: + size = os.path.getsize(p) + except OSError: + continue + if size > best_size: + best, best_size = p, size + return best + + +def _session_log_path(snap_path): + """The ACTIVE session log for a snapshot — mirrors dm_narration_fallback._recover.""" + try: + with open(snap_path, encoding="utf-8") as f: + snap = json.load(f) + except (OSError, ValueError): + return "" + if not isinstance(snap, dict): + return "" + sid = snap.get("active_session_id") + if not sid: + ids = snap.get("session_ids") + if isinstance(ids, list) and ids: + sid = ids[-1] + if not isinstance(sid, str) or not sid or sid != os.path.basename(sid) or sid in (".", ".."): + return "" + return os.path.join(os.path.dirname(snap_path), "sessions", sid + ".jsonl") + + +def _line_count(path): + n = 0 + try: + with open(path, encoding="utf-8") as f: + for _ in f: + n += 1 + except OSError: + return 0 + return n + + +def _is_new_prose(row): + """The same player-facing-prose filter the #357 fallback applies: narration|dialogue with + non-empty text, excluding wrapper heartbeats + setup-brief system notation.""" + if not isinstance(row, dict): + return False + kind = str(row.get("kind") or "narration").strip().lower() + text = str(row.get("text") or "").strip() + if kind not in PROSE_KINDS or not text: + return False + if kind == "narration" and (_is_system_notation(text) or is_wrapper_progress_line(text)): + return False + return True + + +def cmd_mark(state_dir, mark_file): + snap = _snapshot_path(state_dir) + log_path = _session_log_path(snap) if snap else "" + lines = _line_count(log_path) if log_path and os.path.isfile(log_path) else 0 + payload = {"session": os.path.abspath(log_path) if log_path else "", "lines": lines} + with open(mark_file, "w", encoding="utf-8") as f: + json.dump(payload, f) + return 0 + + +def cmd_check(state_dir, mark_file): + try: + with open(mark_file, encoding="utf-8") as f: + mark = json.load(f) + marked_session = str(mark.get("session") or "") + marked_lines = int(mark.get("lines") or 0) + except Exception: + return 0 # unreadable mark -> fail OPEN (assume genuine; legacy behavior) + snap = _snapshot_path(state_dir) + if not snap: + return 1 # nothing recoverable exists at all + cur = _session_log_path(snap) + if not cur or not os.path.isfile(cur): + return 1 + # A DIFFERENT session file than the marked one (the beat started a new session, or no + # session existed at mark time) means every row in it is new — scan from line 0. + skip = marked_lines if os.path.abspath(cur) == marked_session else 0 + try: + with open(cur, encoding="utf-8") as f: + for i, raw in enumerate(f): + if i < skip: + continue + raw = raw.strip() + if not raw: + continue + try: + row = json.loads(raw) + except ValueError: + continue + if _is_new_prose(row): + return 0 # NEW player-facing prose logged this beat -> genuine + except OSError: + return 0 # unreadable log -> fail OPEN + return 1 # nothing new -> anything recovered is recycled pre-beat prose + + +def main(argv): + if len(argv) < 4 or argv[1] not in ("mark", "check"): + print("usage: dm_beat_mark.py mark|check ", file=sys.stderr) + return 0 # never fail a beat over a usage error + try: + return (cmd_mark if argv[1] == "mark" else cmd_check)(argv[2], argv[3]) + except Exception: + return 0 # any internal failure fails OPEN + + +if __name__ == "__main__": + sys.exit(main(sys.argv)) diff --git a/qa/lib_beat_driver.sh b/qa/lib_beat_driver.sh index 86ca217f..33e3e29e 100644 --- a/qa/lib_beat_driver.sh +++ b/qa/lib_beat_driver.sh @@ -127,20 +127,55 @@ clawdnd_dm_narration_or_fallback() { } # clawdnd_resolve_dm_reply REPLY STATE_DIR — the DIRECT-call front door over -# clawdnd_dm_narration_or_fallback (#749c fallback honesty). Sets: -# CLAWDND_DM_REPLY — the resolved reply text (the DM's own, or the recovered prose) -# CLAWDND_FALLBACK_RECOVERED — 1 IFF the #357 fallback recovered the prose (the DM's reply was -# blank and the engine log supplied it), else 0 -# Call it DIRECTLY (never in a command substitution — a subshell would drop both globals), then +# clawdnd_dm_narration_or_fallback (#749c fallback honesty + SYN-01 #757/#745 dead-beat +# classification). Sets: +# CLAWDND_DM_REPLY — the resolved reply text (the DM's own, the recovered prose, +# or "" when the beat FAILED) +# CLAWDND_FALLBACK_RECOVERED — 1 IFF the #357 fallback recovered GENUINE prose (the DM's +# reply was blank and the engine log supplied prose the DM +# logged THIS beat), else 0 +# CLAWDND_DM_BEAT_FAILED — 1 IFF the beat FAILED: the final result event was ERROR-class +# (is_error / api_error_status — its "result" text is the API's +# error string, e.g. "Failed to authenticate…", NEVER a reply), +# or the only recoverable prose PREDATES the pre-beat mark +# (recycling the previous beat's prose would mask a dead beat). +# SYN-01 ORDER OF OPERATIONS: the FINAL result event (noted by clawdnd_dm_final_text in +# $STATE_DIR/.dm_last_result) is classified FIRST — before any fallback — so an error-class +# result can never be chatted as DM prose NOR "recovered" into recycled prose. Every failed +# beat resolves to an EMPTY reply; callers branch on that and record the failure VISIBLY +# (clawdnd_chatlog_dm_failed, or record_dm_reply's blank guard). +# Call it DIRECTLY (never in a command substitution — a subshell would drop the globals), then # read CLAWDND_DM_REPLY. The flag is consumed (and reset) by the next record_dm_reply / # clawdnd_chatlog_dm, which stamps {"fallback_recovered":true} on the dm chat row so behavioral # tallies can later discount a masked-dead beat that was "resolved" with recovered prose. clawdnd_resolve_dm_reply() { - local original="$1" - CLAWDND_DM_REPLY="$(clawdnd_dm_narration_or_fallback "$1" "$2")" + local original="$1" state_dir="$2" last="" + CLAWDND_DM_BEAT_FAILED=0 CLAWDND_FALLBACK_RECOVERED=0 + # SYN-01 leg 1: parse the FINAL result event FIRST. A 401-class failure carries NON-empty + # result text, which used to bypass the empty-only retry AND this fallback and land in chat + # AS DM PROSE. Classify it -> the beat FAILED; never chat the error text. + last="$(cat "$state_dir/.dm_last_result" 2>/dev/null)" + if [ -n "$last" ] && [ -f "$last" ] && clawdnd_dm_result_is_error "$last"; then + echo "[worldos] DM beat FAILED: error-class result event (see the [dm-attempt] line above) — the error text will NOT be chatted as narration" >&2 + CLAWDND_DM_BEAT_FAILED=1 + CLAWDND_DM_REPLY="" + return 0 + fi + CLAWDND_DM_REPLY="$(clawdnd_dm_narration_or_fallback "$original" "$state_dir")" if [ -z "${original//[[:space:]]/}" ] && [ -n "${CLAWDND_DM_REPLY//[[:space:]]/}" ]; then - CLAWDND_FALLBACK_RECOVERED=1 + # The #357 fallback recovered prose. GENUINE recovery = the DM logged NEW prose THIS beat + # (then died before its final reply). If everything recoverable PREDATES the pre-beat mark + # the beat was fully dead and the "recovery" is the PREVIOUS beat's prose — recycling it + # would mask the dead beat (F12-14), so the beat FAILS instead. No mark file (an older / + # external caller) keeps the legacy assume-genuine behavior. + if clawdnd_dm_logged_new_prose "$state_dir"; then + CLAWDND_FALLBACK_RECOVERED=1 + else + echo "[worldos] DM beat FAILED: only recyclable (pre-beat) prose available — refusing to mask a dead beat with the previous beat's narration" >&2 + CLAWDND_DM_BEAT_FAILED=1 + CLAWDND_DM_REPLY="" + fi fi } @@ -273,6 +308,14 @@ PY # behavioral tallies can discount masked-dead beats. Consume-once: the flag resets here. record_dm_reply() { local campaign_id="$1" text="$2" phase="$3" extra='{"engine_logged":true}' plain_extra='' + # SYN-01 (#757 leg 2): NEVER write a blank dm row. A dead beat that recovered nothing used to + # land an unflagged EMPTY chat row (the post-#763 play.sh mode) — invisible to the player AND + # the tallies. Record the wrapper-authored VISIBLE failure beat instead, and warn. + if [ -z "${text//[[:space:]]/}" ]; then + echo "[worldos] warning: ${phase} produced NO narration (dead beat) — recording a visible failure beat instead of a blank row" >&2 + clawdnd_chatlog_dm_failed + return 0 + fi if [ "${CLAWDND_FALLBACK_RECOVERED:-0}" = "1" ]; then extra='{"engine_logged":true,"fallback_recovered":true}' plain_extra='{"fallback_recovered":true}' @@ -299,6 +342,110 @@ clawdnd_chatlog_dm() { CLAWDND_FALLBACK_RECOVERED=0 } +# ── SYN-01 (#757/#745): dead-beat failure classification — the honesty layer ──────────────── +# ~10.5% of DM invocations produce no usable beat (28 no-result + 3x401 of 294 archived files; +# audit 2026-06-11). Three masks made them look "resolved": +# (a) a 401-class failure's NON-empty error text bypassed the empty-only retry + the #357 +# fallback gate and was chatlogged AS DM PROSE; +# (b) a fully-dead beat either recycled the PREVIOUS beat's prose into a hidden row, or wrote +# an unflagged EMPTY dm row — either way the player saw nothing while the harness counted +# a resolved turn; +# (c) the fallback_recovered honesty stamp was dead in every QA runner (local chatlog +# overrides shadowed the lib) and had no consumer. +# These helpers close (a)+(b); (c) is closed by deleting the runner overrides + the +# qa/assert_behavioral.py dm_beat_honesty counter. Flow per beat: +# clawdnd_dm_prebeat_mark (once, BEFORE attempt 1) +# clawdnd_dm_final_text (per attempt — notes the result file + classifies error-class) +# clawdnd_resolve_dm_reply (classification first; failed beats resolve to an EMPTY reply) +# clawdnd_chatlog_dm_failed / record_dm_reply's blank guard (the VISIBLE failure row) + +# The wrapper-authored, PLAYER-VISIBLE failure beat. Chat-only BY DESIGN — deliberately NOT +# routed through log_engine_narration: (1) the #727 substring dedup would swallow the constant +# text on a repeat failure, and an engine_logged stamp would then HIDE the row (app.jsx drops +# engine_logged rows in favor of /events, where the deduped repeat never lands); (2) a failure +# line in the session log would pollute recap/FTS/lean-tail story memory (#763 decontamination) +# and could itself be "recovered" by the NEXT beat's #357 fallback. A plain /chat row renders +# unconditionally in every consumer — visible, exactly once per failure. +CLAWDND_DM_FAILED_BEAT_TEXT="(The tale falters — the Dungeon Master could not resolve this beat. Your last action still stands; give it a moment and try again.)" + +# clawdnd_dm_result_is_error OUT — is the FINAL result event of a DM attempt's stream-json an +# ERROR-class result? The 401 shape (verified verbatim) is subtype:"success", is_error:true, +# api_error_status:401 with the API's error string in .result — so the test is is_error OR an +# api_error_status, NEVER the subtype or the text. A missing/empty file or a stream with no +# result event is NOT error-class (the empty-reply path owns those modes). 0 = error-class. +clawdnd_dm_result_is_error() { + local out="$1" flag + [ -n "$out" ] && [ -s "$out" ] || return 1 + flag="$(jq -rs 'map(select(.type=="result"))[-1] | if . == null then "none" else (((.is_error == true) or ((.api_error_status // null) != null)) | tostring) end' "$out" 2>/dev/null)" + case "$flag" in + true) return 0 ;; + false | none) return 1 ;; + esac + # jq unavailable/unparseable -> the same conservative grep-fallback discipline as + # clawdnd_report_attempt_failure: only the explicit error markers flip it. + grep -q '"is_error"[[:space:]]*:[[:space:]]*true' "$out" 2>/dev/null && return 0 + grep -qE '"api_error_status"[[:space:]]*:[[:space:]]*[0-9]+' "$out" 2>/dev/null && return 0 + return 1 +} + +# clawdnd_dm_final_text OUT STATE_DIR [RC] — the ONE extraction front door for a DM attempt's +# reply text (replaces the bare `jq -rs '… .result // ""'` in every DM wrapper). Notes OUT in +# $STATE_DIR/.dm_last_result (a FILE, because the turn helpers run inside $(...) subshells +# where a global cannot escape) so the caller's clawdnd_resolve_dm_reply can classify the SAME +# final result event — then echoes the final result text, UNLESS the event is ERROR-class: +# then it echoes NOTHING (the "result" text is the API's error string, never a reply) and +# surfaces the real failure + the 401/403 re-auth hint via clawdnd_report_attempt_failure. +# The empty echo also makes the callers' existing empty-only retries fire on error results. +clawdnd_dm_final_text() { + local out="$1" state_dir="$2" rc="${3:-0}" + printf '%s\n' "$out" > "$state_dir/.dm_last_result" 2>/dev/null || true + if clawdnd_dm_result_is_error "$out"; then + clawdnd_report_attempt_failure "$out" "$rc" + return 0 + fi + jq -rs 'map(select(.type=="result"))[-1].result // ""' "$out" 2>/dev/null +} + +# clawdnd_dm_prebeat_mark STATE_DIR — snapshot the active session log's position BEFORE a DM +# beat launches (file: $STATE_DIR/.dm_prebeat_mark), so clawdnd_dm_logged_new_prose can tell a +# GENUINE #357 recovery (NEW prose logged THIS beat, then the turn died) from RECYCLED prose +# (everything recoverable predates the beat — a masked dead beat). Call it ONCE per beat, +# BEFORE attempt 1: a retry must NOT re-mark, or attempt 1's prose would stop counting as this +# beat's. Best-effort (never fails a beat); standalone python — no heredoc-in-$() (bash 3.2). +clawdnd_dm_prebeat_mark() { + local state_dir="$1" + local mark_py="${CLAWDND_LIB_DIR:-$(dirname "${BASH_SOURCE[0]}")}/dm_beat_mark.py" + python3 "$mark_py" mark "$state_dir" "$state_dir/.dm_prebeat_mark" 2>/dev/null || true + return 0 +} + +# clawdnd_dm_logged_new_prose STATE_DIR — did the DM log NEW player-facing prose (narration | +# dialogue; wrapper heartbeats + setup-brief notation excluded, exactly as the #357 fallback +# filters) since the pre-beat mark? 0 = yes (a recovery is GENUINE); 1 = no (anything the +# fallback recovered is RECYCLED pre-beat prose). NO mark file -> 0: an older/external caller +# keeps the legacy assume-genuine behavior; dm_beat_mark.py also fails OPEN internally. +clawdnd_dm_logged_new_prose() { + local state_dir="$1" + local mark="$state_dir/.dm_prebeat_mark" + [ -f "$mark" ] || return 0 + local mark_py="${CLAWDND_LIB_DIR:-$(dirname "${BASH_SOURCE[0]}")}/dm_beat_mark.py" + python3 "$mark_py" check "$state_dir" "$mark" 2>/dev/null +} + +# clawdnd_chatlog_dm_failed — record the wrapper-authored VISIBLE failure beat for a FAILED DM +# beat: ONE /chat dm row carrying {"beat_failed":true} (counted + reported by +# qa/assert_behavioral.py's dm_beat_honesty; the discount/gate policy stays #757's call). The +# row text is CLAWDND_DM_FAILED_BEAT_TEXT — never an error string, never recycled prose, never +# blank, never hidden (no engine_logged stamp — see the constant's comment). Consume-once on +# the resolve flags, mirroring clawdnd_chatlog_dm. Reads ambient $CHAT exactly as chatlog does. +clawdnd_chatlog_dm_failed() { + CLAWDND_DM_BEATS_FAILED=$((${CLAWDND_DM_BEATS_FAILED:-0} + 1)) + echo "[worldos] beat FAILED — visible failure beat recorded (beats_failed=$CLAWDND_DM_BEATS_FAILED this run)" >&2 + chatlog dm "$CLAWDND_DM_FAILED_BEAT_TEXT" '{"beat_failed":true}' + CLAWDND_FALLBACK_RECOVERED=0 + CLAWDND_DM_BEAT_FAILED=0 +} + # LIVE-PROGRESS + WRAPPER HEARTBEAT (#623 — the ONE shared implementation of the perceived-latency fix). # # The bug #623 ("beat silently DROPPED / HUNG >10min, no recovery") was a PERCEIVED-latency defect, not diff --git a/qa/run_duo.sh b/qa/run_duo.sh index e27ef533..4e09bd5a 100755 --- a/qa/run_duo.sh +++ b/qa/run_duo.sh @@ -132,12 +132,15 @@ COMBINED="$T/$RUN.jsonl"; : > "$COMBINED" # dashboard can show the PROTAGONIST acting — not just the DM narrating. The DM's own # stream (COMBINED) doesn't echo the player's turns, so we capture both sides here. CHAT="$T/$RUN.chat.jsonl"; : > "$CHAT" -chatlog() { python3 -c 'import json,sys;open(sys.argv[1],"a").write(json.dumps({"role":sys.argv[2],"text":sys.argv[3]})+"\n")' "$CHAT" "$1" "$2"; } +# chatlog is the SHARED lib implementation (qa/lib_beat_driver.sh, reads ambient $CHAT at call +# time). SYN-01/F12-7: a local 2-arg override here used to shadow it AFTER sourcing the lib, +# silently discarding clawdnd_chatlog_dm's {"fallback_recovered":true} honesty stamp — never +# re-define chatlog in a runner. echo "[duo] run=$RUN world=$WORLD beats=$BEATS dm=$DSID player=$PSID" # $1=role(player|dm) $2=session-id $3=first?(1/0) $4=message ; echoes the agent's reply text turn() { - local role="$1" sid="$2" first="$3" msg="$4" out resume=() extra=() + local role="$1" sid="$2" first="$3" msg="$4" out resume=() extra=() rc=0 [ "$first" = "0" ] && resume=(--resume "$sid") || resume=(--session-id "$sid") if [ "$role" = "dm" ]; then # LEAN beats (CLAWDND_LEAN_BEATS=1): a continuing DM beat starts a FRESH session + a @@ -162,8 +165,13 @@ turn() { 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" - jq -rs 'map(select(.type=="result"))[-1].result // ""' "$out" 2>/dev/null + # 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 + # now fires on error results too instead of chatting them as DM prose. + clawdnd_dm_final_text "$out" "$STATE_DIR" "$rc" else claude -p "$msg" "${resume[@]}" --mcp-config "$PLAYER_CFG" --strict-mcp-config \ --model "$CLAWDND_ACTOR_MODEL" --permission-mode bypassPermissions --max-budget-usd "$BUDGET" \ @@ -175,7 +183,12 @@ turn() { # A turn, with ONE retry on empty output (a transient CLI/auth/rate blip shouldn't # silently truncate a run). Echoes the reply text (possibly empty after the retry). turn_retry() { - local r; r="$(turn "$@")" + local r + # SYN-01: pre-beat log-tail mark — ONCE per beat, BEFORE attempt 1 (the retry must not + # re-mark: attempt 1's logged prose still counts as this beat's), so the resolve path can + # tell a GENUINE #357 recovery from RECYCLED pre-beat prose. File-based (subshell-safe). + clawdnd_dm_prebeat_mark "$STATE_DIR" + r="$(turn "$@")" 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 @@ -246,7 +259,14 @@ Do the setup now: start_world(\"$WORLD\"), start_session, then seat THEIR charac # line (empty final reply) — so a tool-final-but-narrated turn isn't mistaken for silence. clawdnd_resolve_dm_reply "$DMSG" "$STATE_DIR"; DMSG="$CLAWDND_DM_REPLY" echo "[duo] DM opened: ${DMSG:0:120}…" -[ -z "$DMSG" ] && { echo "[duo] DM produced no opening — aborting (see $COMBINED)" >&2; exit 1; } +# SYN-01: an empty resolved reply is a FAILED beat (error-class result, recycled-only prose, or +# nothing recovered). Record the wrapper-authored VISIBLE failure row — never the error text, +# never a blank/hidden row — then abort loudly as before. +if [ -z "$DMSG" ]; then + clawdnd_chatlog_dm_failed + echo "[duo] DM produced no opening — aborting (see $COMBINED)" >&2 + exit 1 +fi clawdnd_chatlog_dm "$DMSG" # Resolve the campaign id the cold open just minted (for the lean re-ground; harmless when @@ -326,7 +346,13 @@ $EVENT_ADV")" # tool call but logged real prose isn't mis-flagged as a silent DM (and isn't blank in chat). clawdnd_resolve_dm_reply "$DMSG" "$STATE_DIR"; DMSG="$CLAWDND_DM_REPLY" echo "[duo] beat $b DM: ${DMSG:0:100}…" - [ -z "$DMSG" ] && { echo "[duo] DM went silent at beat $b; stopping early"; break; } + # SYN-01: an empty resolved reply is a FAILED beat — record the visible failure row (counted + # by assert_behavioral's dm_beat_honesty) instead of masking with error text/recycled prose. + if [ -z "$DMSG" ]; then + clawdnd_chatlog_dm_failed + echo "[duo] DM went silent at beat $b; stopping early" + break + fi clawdnd_chatlog_dm "$DMSG" # C — soft clock-tick backstop: if the DM didn't move the clock this beat, advance one diff --git a/qa/run_party.sh b/qa/run_party.sh index 332e75f4..54ba538c 100755 --- a/qa/run_party.sh +++ b/qa/run_party.sh @@ -166,16 +166,22 @@ PSID="$(python3 -c 'import uuid;print(uuid.uuid4())')" DM_BRIEF="$(cat qa/play_dm_duo.txt)"; PLAYER_BRIEF="$(cat "$PLAYER_PROMPT_FILE")" COMBINED="$T/$RUN.jsonl"; : > "$COMBINED" CHAT="$T/$RUN.chat.jsonl"; : > "$CHAT" -chatlog() { python3 -c 'import json,sys;open(sys.argv[1],"a").write(json.dumps({"role":sys.argv[2],"text":sys.argv[3]})+"\n")' "$CHAT" "$1" "$2"; } +# chatlog is the SHARED lib implementation (qa/lib_beat_driver.sh, reads ambient $CHAT at call +# time). SYN-01/F12-7: a local 2-arg override here used to shadow it AFTER sourcing the lib, +# silently discarding clawdnd_chatlog_dm's {"fallback_recovered":true} honesty stamp — never +# re-define chatlog in a runner. echo "[party] run=$RUN world=$WORLD beats=$BEATS companions=$NUM_COMP dm=$DSID player=$PSID" # A single agent turn. $1=kind(dm|actor) $2=session-id $3=first?(1/0) $4=message $5=mcp-cfg # DM gets the plugin + stream-json (tool calls land in COMBINED); an actor gets ONLY its # facade config (--strict-mcp-config) and json output. Carries --max-budget-usd (per call). turn() { - local kind="$1" sid="$2" first="$3" msg="$4" cfg="${5:-}" out resume=() + local kind="$1" sid="$2" first="$3" msg="$4" cfg="${5:-}" out resume=() rc=0 [ "$first" = "0" ] && resume=(--resume "$sid") || resume=(--session-id "$sid") if [ "$kind" = "dm" ]; then + # SYN-01: pre-beat log-tail mark (once per beat — this runner's DM turns are single-attempt) + # so the caller's resolve can tell a GENUINE #357 recovery from RECYCLED pre-beat prose. + clawdnd_dm_prebeat_mark "$STATE_DIR" # EFFORT TIER (shared helper, qa/lib_beat_driver.sh) — SAME implementation scripts/play.sh, # qa/run_duo.sh, and scripts/play_party.sh use, so the harnesses can't drift: --effort max on # the cold open (one-time world-build), --effort medium on continuing beats (the bulk — cuts @@ -186,8 +192,11 @@ turn() { claude -p "$msg" "${resume[@]}" --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" - jq -rs 'map(select(.type=="result"))[-1].result // ""' "$out" 2>/dev/null + # SYN-01: shared classification front door — notes $out for the caller's resolve and echoes + # NOTHING on an error-class result (a 401's "result" text is never a reply). + clawdnd_dm_final_text "$out" "$STATE_DIR" "$rc" else out="$T/$RUN.actor.$(date +%s%N).jsonl" claude -p "$msg" "${resume[@]}" --mcp-config "$cfg" --strict-mcp-config \ @@ -305,7 +314,13 @@ $beat0_block Resolve each declared move through the engine; voice the world and any NPC; let the companions be PRESENT (the player and companions are separate people with their own agency — you narrate the RESULT of their declared moves, never invent a companion's internal choice). End by handing the open moment to the PLAYER.")" # #357: recover engine-logged narration if the DM turn ended on a tool call (empty reply). clawdnd_resolve_dm_reply "$DMSG" "$STATE_DIR"; DMSG="$CLAWDND_DM_REPLY" -[ -z "$DMSG" ] && { echo "[party] DM produced no opening — aborting (see $COMBINED)" >&2; exit 1; } +# SYN-01: an empty resolved reply is a FAILED beat — record the wrapper-authored VISIBLE +# failure row (never error text, never a blank/hidden row), then abort loudly as before. +if [ -z "$DMSG" ]; then + clawdnd_chatlog_dm_failed + echo "[party] DM produced no opening — aborting (see $COMBINED)" >&2 + exit 1 +fi clawdnd_chatlog_dm "$DMSG"; AGENT_TURNS=$((AGENT_TURNS + 1)) echo "[party] DM opened: ${DMSG:0:120}…" @@ -329,7 +344,13 @@ Then PLAY the next beat as a full lived scene — NOT a fragment: any NPC (or co # turn ≠ silence; keeps the chat non-blank on a resolved beat). clawdnd_resolve_dm_reply "$DMSG" "$STATE_DIR"; DMSG="$CLAWDND_DM_REPLY" echo "[party] beat $b DM: ${DMSG:0:120}…" - [ -z "$DMSG" ] && { echo "[party] DM went silent at beat $b; stopping early"; break; } + # SYN-01: an empty resolved reply is a FAILED beat — record the visible failure row (counted + # by assert_behavioral's dm_beat_honesty) instead of masking with error text/recycled prose. + if [ -z "$DMSG" ]; then + clawdnd_chatlog_dm_failed + echo "[party] DM went silent at beat $b; stopping early" + break + fi clawdnd_chatlog_dm "$DMSG"; AGENT_TURNS=$((AGENT_TURNS + 1)) done diff --git a/qa/ui_playtest.sh b/qa/ui_playtest.sh index 3e68c92c..34378372 100755 --- a/qa/ui_playtest.sh +++ b/qa/ui_playtest.sh @@ -135,7 +135,10 @@ echo "[uipt] viewer ready." # --- DM turn helper (claude -p, full plugin, resumed) ------------------------ DSID="$(python3 -c 'import uuid;print(uuid.uuid4())')" DM_BRIEF="$(cat "$ROOT/qa/play_dm_duo.txt")" -chatlog() { python3 -c 'import json,sys;open(sys.argv[1],"a").write(json.dumps({"role":sys.argv[2],"text":sys.argv[3]})+"\n")' "$CHAT" "$1" "$2"; } +# chatlog is the SHARED lib implementation (qa/lib_beat_driver.sh, reads ambient $CHAT at call +# time). SYN-01/F12-7: a local 2-arg override here used to shadow it AFTER sourcing the lib, +# silently discarding clawdnd_chatlog_dm's {"fallback_recovered":true} honesty stamp — never +# re-define chatlog in a runner. # #745 (the newbie mid-stream-stall give-up): the GUI-sweep DM driver MUST bound every beat exactly # like scripts/play.sh's dm_turn — previously this helper ran `claude -p` with NO `timeout`, NO retry, # and NO fallback, so a DM turn that streamed partial prose via /events and then FROZE mid-generation @@ -151,6 +154,9 @@ chatlog() { python3 -c 'import json,sys;open(sys.argv[1],"a").write(json.dumps({ CLAWDND_DM_MODEL="$DM_MODEL" dm_turn() { local first="$1" msg="$2" out resume=() beat_timeout rc + # SYN-01: pre-beat log-tail mark (once per beat — this driver is single-attempt) so the + # caller's resolve can tell a GENUINE #357 recovery from RECYCLED pre-beat prose. + clawdnd_dm_prebeat_mark "$STATE_DIR" [ "$first" = "0" ] && resume=(--resume "$DSID") || resume=(--session-id "$DSID") beat_timeout="$(clawdnd_dm_timeout "$first")" out="$RUNDIR/dm/turn.$(date +%s%N).jsonl" @@ -161,11 +167,13 @@ dm_turn() { rc=$? [ "$rc" -ne 0 ] && echo "[uipt] DM turn rc=$rc (timeout=${beat_timeout}s) — relying on engine-logged narration fallback" >&2 cat "$out" >> "$COMBINED" - # Echo the beat's RAW final result text. The #357 fallback (recover the engine-logged narration - # tail when a killed/failed beat left this empty, so the turn STILL resolves on /chat) is applied - # by the CALLER via clawdnd_resolve_dm_reply — a direct call, because dm_turn runs in a command + # Echo the beat's final result text via the SYN-01 shared classification front door: it 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). The #357 fallback (recover + # the engine-logged narration tail when a killed/failed beat left this empty) is applied by + # the CALLER via clawdnd_resolve_dm_reply — a direct call, because dm_turn runs in a command # substitution where the #749c fallback_recovered flag (a global) could never escape the subshell. - jq -rs 'map(select(.type=="result"))[-1].result // ""' "$out" 2>/dev/null + clawdnd_dm_final_text "$out" "$STATE_DIR" "$rc" } # --- DM opens the scene so a LIVE, playable game exists (the launcher's Chronicles @@ -180,8 +188,15 @@ Begin a SOLO session for a brand-new human player in this world: start_world(\"$ # #357/#749c: recover the engine-logged narration tail when the turn died with no result text; # a recovered reply stamps fallback_recovered:true on the dm chat row (clawdnd_chatlog_dm). clawdnd_resolve_dm_reply "$DMSG" "$STATE_DIR"; DMSG="$CLAWDND_DM_REPLY" -[ -z "$DMSG" ] && echo "[uipt] WARN: DM produced no opening (see $RUNDIR/dm/dm.err) — the player may land in a thin scene." >&2 -clawdnd_chatlog_dm "${DMSG:-The scene is set. What do you do?}" +# SYN-01: an empty resolved reply is a FAILED beat. The old masking default ("The scene is +# set. What do you do?") pretended a scene existed; record the wrapper-authored VISIBLE failure +# row instead — it is still a real turn-END dm row, so the client's pending state clears. +if [ -z "$DMSG" ]; then + echo "[uipt] WARN: DM produced no opening (see $RUNDIR/dm/dm.err) — recording a visible failure beat; the player may land in a thin scene." >&2 + clawdnd_chatlog_dm_failed +else + clawdnd_chatlog_dm "$DMSG" +fi # --- background DM-resolver loop: tail $MOVES, resolve each new move, append narration # to $CHAT (the UI shows it via /chat). Identical shape to play_human.sh's loop. Runs @@ -201,8 +216,14 @@ $PMSG Resolve it through the engine (roll checks, apply casts/attacks, voice NPCs) and narrate the next beat as a played scene. Hand the moment back to the player.")" # #357/#749c: same recovery + honesty stamp as the opening turn (direct call, see dm_turn). + # SYN-01: an empty resolved reply is a FAILED beat — the visible failure row replaces the + # old "..." masking default (still a turn-END dm row, so the client's pending clears). clawdnd_resolve_dm_reply "$DMSG" "$STATE_DIR"; DMSG="$CLAWDND_DM_REPLY" - clawdnd_chatlog_dm "${DMSG:-...}" + if [ -z "$DMSG" ]; then + clawdnd_chatlog_dm_failed + else + clawdnd_chatlog_dm "$DMSG" + fi else sleep 2 fi diff --git a/scripts/play.sh b/scripts/play.sh index bfbb8bfe..1850170b 100755 --- a/scripts/play.sh +++ b/scripts/play.sh @@ -257,6 +257,10 @@ fi # deadline via clawdnd_dm_retry_timeout. Echoes the DM's final text. dm_turn() { local first="$1" msg="$2" campaign_id="${3:-}" out resume=() extra=() rc beat_timeout + # SYN-01: pre-beat log-tail mark — ONCE per beat, BEFORE attempt 1 (the in-function retry + # below must not re-mark: attempt 1's logged prose still counts as this beat's), so the + # caller's clawdnd_resolve_dm_reply can tell a GENUINE #357 recovery from RECYCLED prose. + clawdnd_dm_prebeat_mark "$STATE_DIR" # #623: prepend the live-progress rule (the ONE shared CLAWDND_LIVE_PROGRESS_RULE in # qa/lib_beat_driver.sh — parity with scripts/play_party.sh + scripts/play_codex_dm.sh) so the DM # logs an EARLY /events narration beat. Its ABSENCE in this SOLO path was the #623 bug: the DM @@ -332,7 +336,10 @@ dm_turn() { [ "$rc" -ne 0 ] && echo "[play] DM turn retry also rc=$rc — relying on engine-logged narration" >&2 fi cat "$out" >> "$COMBINED" 2>/dev/null - jq -rs 'map(select(.type=="result"))[-1].result // ""' "$out" 2>/dev/null + # SYN-01: shared classification front door — notes the FINAL attempt's $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 narration), surfacing the re-auth hint instead. + clawdnd_dm_final_text "$out" "$STATE_DIR" "$rc" } # Launch the dashboard pointed at THIS game; setting CLAWDND_PLAYER_MOVES flips the diff --git a/scripts/play_party.sh b/scripts/play_party.sh index 0e82fccc..39c57eea 100755 --- a/scripts/play_party.sh +++ b/scripts/play_party.sh @@ -298,6 +298,10 @@ turn() { local kind="$1" sid="$2" first="$3" msg="$4" cfg="${5:-}" out resume=() extra=() [ "$first" = "0" ] && resume=(--resume "$sid") || resume=(--session-id "$sid") if [ "$kind" = "dm" ]; then + # SYN-01: pre-beat log-tail mark — ONCE per beat, BEFORE attempt 1 (the in-function retry + # below must not re-mark: attempt 1's logged prose still counts as this beat's), so the + # caller's clawdnd_resolve_dm_reply can tell a GENUINE #357 recovery from RECYCLED prose. + clawdnd_dm_prebeat_mark "$STATE_DIR" # #623: prepend the live-progress rule so the DM logs an early /events narration beat (parity # with play_codex_dm.sh) — without it the long beat shows blank → the perceived drop/hang. msg="$CLAWDND_LIVE_PROGRESS_RULE"$'\n\n'"$msg" @@ -361,7 +365,10 @@ turn() { _dm_invoke; rc=$? fi cat "$out" >> "$COMBINED" - jq -rs 'map(select(.type=="result"))[-1].result // ""' "$out" 2>/dev/null + # SYN-01: shared classification front door — notes the FINAL attempt's $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 narration), surfacing the re-auth hint instead. + 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 \ diff --git a/servers/engine/tests/test_dead_beat_classification.py b/servers/engine/tests/test_dead_beat_classification.py new file mode 100644 index 00000000..b56b89e0 --- /dev/null +++ b/servers/engine/tests/test_dead_beat_classification.py @@ -0,0 +1,512 @@ +"""SYN-01 (#757 / #745) — dead-beat masking & failure classification. + +Three interlocking masks made ~10.5% of DM invocations look "resolved" while the player got +nothing (or worse, an auth error rendered as narration): + + (a) a 401-class ``claude -p`` failure carries NON-empty result text (verified verbatim: + ``subtype:"success", is_error:true, api_error_status:401``) — it bypassed the empty-only + retry (qa/run_duo.sh turn_retry) AND the empty-only #357 fallback gate and was chatlogged + AS DM PROSE ("Failed to authenticate…" as narration); + (b) a fully-dead beat's #357 fallback recycled the PREVIOUS beat's prose (or, post-#763 in the + heartbeat lanes, ``record_dm_reply`` wrote an unflagged EMPTY dm row) — the beat looked + resolved while the player saw nothing new; + (c) three QA runners (qa/run_duo.sh, qa/ui_playtest.sh, qa/run_party.sh) re-defined a 3-arg + ``chatlog`` AFTER sourcing the lib, silently discarding ``clawdnd_chatlog_dm``'s + ``{"fallback_recovered":true}`` honesty stamp — and nothing in qa/assert_behavioral.py + consumed the stamp even where it worked. + +These tests pin the fix: the FINAL result event is classified FIRST (error-class ⇒ the beat +FAILED — never chat the error text, never fallback-recycle, surface the re-auth hint via the +existing clawdnd_report_attempt_failure pattern); ``record_dm_reply`` refuses blank text and +records a wrapper-authored VISIBLE failure beat stamped ``{"beat_failed":true}``; the pre-beat +log-tail mark preserves the GENUINE #357 win (NEW prose logged this beat, then the turn died); +the 3 chatlog overrides are deleted so the shared lib (incl. the stamp) is the single +implementation; and qa/assert_behavioral.py counts + reports both stamps (gate policy stays +#757's call — the counters never flip RED by themselves). + +Bash helpers run under ``/bin/bash`` exactly as the play/QA wrappers invoke them (macOS system +bash 3.2-clean), mirroring tests/test_heartbeat_repair.py. +""" + +from __future__ import annotations + +import json +import re +import subprocess +import sys +from pathlib import Path + +import pytest + +ENGINE_DIR = Path(__file__).resolve().parents[1] +REPO_ROOT = ENGINE_DIR.parents[1] +LIB = REPO_ROOT / "qa" / "lib_beat_driver.sh" + +PROSE_1 = "You step into the Heapside warren as lamplight gutters along the brick." +PROSE_2 = "Mirelda lowers her voice; the ledger between you suddenly feels heavier." +ERR_TEXT = "Failed to authenticate: invalid API key provided" + +QA_RUNNERS = ("qa/run_duo.sh", "qa/ui_playtest.sh", "qa/run_party.sh") +ALL_DM_WRAPPERS = QA_RUNNERS + ("scripts/play.sh", "scripts/play_party.sh") + + +def _bash(script: str) -> subprocess.CompletedProcess: + return subprocess.run( + ["/bin/bash", "-c", script], capture_output=True, text=True, cwd=str(REPO_ROOT) + ) + + +def _hdr(state: Path, chat: Path) -> str: + return f'set -u; ROOT="{REPO_ROOT}"; STATE_DIR="{state}"; CHAT="{chat}"; . "{LIB}"\n' + + +def _chat_rows(chat: Path) -> list[dict]: + if not chat.exists(): + return [] + return [ + json.loads(line) + for line in chat.read_text(encoding="utf-8").splitlines() + if line.strip() + ] + + +def _write_result_jsonl(path: Path, *, result: str, is_error: bool = False, + status: int | None = None, subtype: str = "success") -> Path: + """A minimal stream-json transcript ending on a final ``result`` event — the 401 shape is + the audit's verified-verbatim sample (subtype:"success", is_error:true, api_error_status).""" + ev: dict = {"type": "result", "subtype": subtype, "is_error": is_error, "result": result} + if status is not None: + ev["api_error_status"] = status + path.write_text( + json.dumps({"type": "system", "subtype": "init"}) + "\n" + json.dumps(ev) + "\n", + encoding="utf-8", + ) + return path + + +def _seed_campaign(state: Path, prose_rows: list[str]) -> Path: + """A minimal snapshot + session log shaped exactly like the engine's on-disk format (the + same fixture shape test_heartbeat_repair.py uses), so the #357 fallback can recover prose.""" + camp = state / "campaigns" / "c1" + (camp / "sessions").mkdir(parents=True) + (camp / "snapshot.json").write_text( + json.dumps({"id": "c1", "active_session_id": "s1", "day": 1}), encoding="utf-8" + ) + log = camp / "sessions" / "s1.jsonl" + log.write_text( + "".join( + json.dumps({"t": float(i), "kind": "narration", "text": t}) + "\n" + for i, t in enumerate(prose_rows) + ), + encoding="utf-8", + ) + return log + + +# ── leg 1: the FINAL result event is classified FIRST ──────────────────────────────────────── + + +def test_final_text_error_class_echoes_nothing_and_surfaces_reauth_hint(tmp_path): + """A 401-class result's text is the API's error string, NEVER a reply: the shared extraction + front door must echo NOTHING (so the empty-only retries now fire on error results too) and + surface the failure + re-auth hint via the existing clawdnd_report_attempt_failure pattern.""" + out = _write_result_jsonl(tmp_path / "out.jsonl", result=ERR_TEXT, is_error=True, status=401) + chat = tmp_path / "chat.jsonl" + script = ( + _hdr(tmp_path, chat) + + f'txt="$(clawdnd_dm_final_text "{out}" "$STATE_DIR" 1)"\n' + + 'printf "TXT[%s]\\n" "$txt"\n' + ) + r = _bash(script) + assert r.returncode == 0, r.stderr + assert "TXT[]" in r.stdout, f"error text leaked as the reply: {r.stdout!r}" + assert ERR_TEXT not in r.stdout + assert "401" in r.stderr, f"the HTTP status must be surfaced: {r.stderr!r}" + assert "AUTH" in r.stderr and "NOT retryable" in r.stderr, ( + "the 401/403 re-auth operator hint (clawdnd_report_attempt_failure) must fire" + ) + # The pointer file lets the caller's resolve classify the SAME final result event. + ptr = tmp_path / ".dm_last_result" + assert ptr.read_text(encoding="utf-8").strip() == str(out) + + +def test_final_text_healthy_result_passes_through(tmp_path): + out = _write_result_jsonl(tmp_path / "out.jsonl", result=PROSE_1) + script = ( + _hdr(tmp_path, tmp_path / "chat.jsonl") + + f'txt="$(clawdnd_dm_final_text "{out}" "$STATE_DIR" 0)"\n' + + 'printf "TXT[%s]\\n" "$txt"\n' + ) + r = _bash(script) + assert r.returncode == 0, r.stderr + assert f"TXT[{PROSE_1}]" in r.stdout + assert "[dm-attempt]" not in r.stderr, "a healthy result must not be reported as a failure" + + +def test_final_text_resultless_stream_is_empty_not_error(tmp_path): + """A timeout-killed attempt (no result event at all) is NOT error-class here — the callers' + rc-based reporting + the empty-reply path own that mode (today's behavior, preserved).""" + out = tmp_path / "out.jsonl" + out.write_text(json.dumps({"type": "system", "subtype": "init"}) + "\n", encoding="utf-8") + script = ( + _hdr(tmp_path, tmp_path / "chat.jsonl") + + f'txt="$(clawdnd_dm_final_text "{out}" "$STATE_DIR" 124)"\n' + + 'printf "TXT[%s]\\n" "$txt"\n' + ) + r = _bash(script) + assert r.returncode == 0, r.stderr + assert "TXT[]" in r.stdout + assert "[dm-attempt]" not in r.stderr + + +def test_resolve_classifies_error_result_as_failed_beat_never_recycles(tmp_path): + """The dead-beat mask, leg (a)+(b) together: an error-class final result fails the beat — + the reply is EMPTY (no error text, no recycled prose even though the log has prior prose) + and CLAWDND_DM_BEAT_FAILED=1.""" + _seed_campaign(tmp_path, [PROSE_1]) # recycle bait: the previous beat's prose is recoverable + out = _write_result_jsonl(tmp_path / "out.jsonl", result=ERR_TEXT, is_error=True, status=401) + chat = tmp_path / "chat.jsonl" + script = ( + _hdr(tmp_path, chat) + + f'_="$(clawdnd_dm_final_text "{out}" "$STATE_DIR" 1)"\n' + + 'clawdnd_resolve_dm_reply "" "$STATE_DIR"\n' + + 'printf "failed=%s recovered=%s reply=[%s]\\n" "$CLAWDND_DM_BEAT_FAILED" "$CLAWDND_FALLBACK_RECOVERED" "$CLAWDND_DM_REPLY"\n' + ) + r = _bash(script) + assert r.returncode == 0, r.stderr + assert "failed=1" in r.stdout, r.stdout + assert "recovered=0" in r.stdout + assert "reply=[]" in r.stdout, f"a failed beat must resolve to an EMPTY reply: {r.stdout!r}" + assert ERR_TEXT not in r.stdout and PROSE_1 not in r.stdout + + +def test_resolve_healthy_reply_unchanged(tmp_path): + """A normal beat (healthy result event + non-empty reply) is byte-identical to today.""" + _seed_campaign(tmp_path, [PROSE_1]) + out = _write_result_jsonl(tmp_path / "out.jsonl", result=PROSE_2) + script = ( + _hdr(tmp_path, tmp_path / "chat.jsonl") + + f'_="$(clawdnd_dm_final_text "{out}" "$STATE_DIR" 0)"\n' + + f'clawdnd_resolve_dm_reply {PROSE_2!r} "$STATE_DIR"\n' + + 'printf "failed=%s recovered=%s reply=[%s]\\n" "$CLAWDND_DM_BEAT_FAILED" "$CLAWDND_FALLBACK_RECOVERED" "$CLAWDND_DM_REPLY"\n' + ) + r = _bash(script) + assert r.returncode == 0, r.stderr + assert "failed=0" in r.stdout and "recovered=0" in r.stdout + assert f"reply=[{PROSE_2}]" in r.stdout + + +# ── leg 2: recycled-vs-genuine recovery (the pre-beat log-tail mark) ───────────────────────── + + +def test_resolve_recycled_prose_is_a_failed_beat(tmp_path): + """Both attempts die with NO new prose logged: the #357 fallback would recover the PREVIOUS + beat's prose. With a pre-beat mark in place that recovery is RECYCLED ⇒ the beat FAILED + (reply empty), instead of masking the dead beat as resolved (F12-14).""" + _seed_campaign(tmp_path, [PROSE_1]) + out = _write_result_jsonl(tmp_path / "out.jsonl", result="") # died: empty result text + script = ( + _hdr(tmp_path, tmp_path / "chat.jsonl") + + 'clawdnd_dm_prebeat_mark "$STATE_DIR"\n' + + f'_="$(clawdnd_dm_final_text "{out}" "$STATE_DIR" 124)"\n' + + 'clawdnd_resolve_dm_reply "" "$STATE_DIR"\n' + + 'printf "failed=%s recovered=%s reply=[%s]\\n" "$CLAWDND_DM_BEAT_FAILED" "$CLAWDND_FALLBACK_RECOVERED" "$CLAWDND_DM_REPLY"\n' + ) + r = _bash(script) + assert r.returncode == 0, r.stderr + assert "failed=1" in r.stdout, f"recycled recovery must FAIL the beat: {r.stdout!r}" + assert "recovered=0" in r.stdout + assert "reply=[]" in r.stdout + assert PROSE_1 not in r.stdout, "the previous beat's prose must never be recycled" + + +def test_resolve_new_prose_after_mark_is_genuine_357_recovery(tmp_path): + """The genuine #357 win is PRESERVED: the DM logged NEW prose THIS beat (after the mark) + and then died before its final reply ⇒ the recovery is real (fallback_recovered=1).""" + log = _seed_campaign(tmp_path, [PROSE_1]) + out = _write_result_jsonl(tmp_path / "out.jsonl", result="") + mark = _hdr(tmp_path, tmp_path / "chat.jsonl") + 'clawdnd_dm_prebeat_mark "$STATE_DIR"\n' + r = _bash(mark) + assert r.returncode == 0, r.stderr + # The DM logs NEW prose mid-beat (P2), then the turn dies. + with log.open("a", encoding="utf-8") as fh: + fh.write(json.dumps({"t": 99.0, "kind": "narration", "text": PROSE_2}) + "\n") + script = ( + _hdr(tmp_path, tmp_path / "chat.jsonl") + + f'_="$(clawdnd_dm_final_text "{out}" "$STATE_DIR" 124)"\n' + + 'clawdnd_resolve_dm_reply "" "$STATE_DIR"\n' + + 'printf "failed=%s recovered=%s\\nreply=[%s]\\n" "$CLAWDND_DM_BEAT_FAILED" "$CLAWDND_FALLBACK_RECOVERED" "$CLAWDND_DM_REPLY"\n' + ) + r = _bash(script) + assert r.returncode == 0, r.stderr + assert "failed=0" in r.stdout, f"a genuine recovery must NOT fail the beat: {r.stdout!r}" + assert "recovered=1" in r.stdout + assert PROSE_2 in r.stdout, "the NEW prose must be the recovered reply" + + +def test_resolve_without_mark_keeps_legacy_recovery(tmp_path): + """No pre-beat mark (an older/external caller) ⇒ assume-genuine, exactly today's behavior — + the classification layer must never regress a caller that doesn't mark.""" + _seed_campaign(tmp_path, [PROSE_1]) + script = ( + _hdr(tmp_path, tmp_path / "chat.jsonl") + + 'clawdnd_resolve_dm_reply "" "$STATE_DIR"\n' + + 'printf "failed=%s recovered=%s reply=[%s]\\n" "$CLAWDND_DM_BEAT_FAILED" "$CLAWDND_FALLBACK_RECOVERED" "$CLAWDND_DM_REPLY"\n' + ) + r = _bash(script) + assert r.returncode == 0, r.stderr + assert "failed=0" in r.stdout and "recovered=1" in r.stdout + assert PROSE_1 in r.stdout + + +def test_wrapper_heartbeat_lane_dead_beat_ends_in_visible_failure_row(tmp_path): + """The HEARTBEAT lane (play.sh/play_party.sh, post-#763): a dead beat's only post-mark row + is the wrapper heartbeat, which BREAKS the #357 fallback's trailing block — so resolve + yields an EMPTY reply (no recycle, no recovery), and the downstream blank guard records the + wrapper-authored VISIBLE failure beat instead of the old unflagged EMPTY row. ALSO pins + that the heartbeat row alone never counts as a genuine recovery (recovered=0).""" + import wrapper_progress + + log = _seed_campaign(tmp_path, [PROSE_1]) + out = _write_result_jsonl(tmp_path / "out.jsonl", result="") + chat = tmp_path / "chat.jsonl" + r = _bash(_hdr(tmp_path, chat) + 'clawdnd_dm_prebeat_mark "$STATE_DIR"\n') + assert r.returncode == 0, r.stderr + with log.open("a", encoding="utf-8") as fh: + fh.write( + json.dumps( + {"t": 99.0, "kind": "narration", + "text": wrapper_progress.WRAPPER_OPENING_PROGRESS_LINE} + ) + "\n" + ) + script = ( + _hdr(tmp_path, chat) + + f'_="$(clawdnd_dm_final_text "{out}" "$STATE_DIR" 124)"\n' + + 'clawdnd_resolve_dm_reply "" "$STATE_DIR"\n' + + 'printf "recovered=%s reply=[%s]\\n" "$CLAWDND_FALLBACK_RECOVERED" "$CLAWDND_DM_REPLY"\n' + + 'record_dm_reply "c1" "$CLAWDND_DM_REPLY" beat\n' + ) + r = _bash(script) + assert r.returncode == 0, r.stderr + assert "recovered=0" in r.stdout + assert "reply=[]" in r.stdout, ( + f"a heartbeat row alone must never be recovered as this beat's prose: {r.stdout!r}" + ) + rows = _chat_rows(chat) + assert len(rows) == 1 and rows[0].get("beat_failed") is True, ( + f"the dead heartbeat-lane beat must surface as ONE visible failure row: {rows}" + ) + assert PROSE_1 not in rows[0]["text"] + + +# ── leg 2: record_dm_reply blank guard + the visible failure beat ──────────────────────────── + + +def test_record_dm_reply_blank_records_visible_failure_row(tmp_path): + """Blank text never writes a blank/hidden dm row: the wrapper-authored VISIBLE failure beat + is recorded instead — stamped {"beat_failed":true}, NOT engine_logged (so the client always + renders it), logged exactly once, and warned on stderr.""" + chat = tmp_path / "chat.jsonl" + script = _hdr(tmp_path, chat) + 'record_dm_reply "" "" beat\n' + r = _bash(script) + assert r.returncode == 0, r.stderr + assert "warning" in r.stderr.lower() and "failure beat" in r.stderr.lower(), r.stderr + rows = _chat_rows(chat) + assert len(rows) == 1, f"exactly ONE failure row expected, got: {rows}" + row = rows[0] + assert row["role"] == "dm" + assert row.get("beat_failed") is True, f"the failure row must be stamped: {row}" + assert row["text"].strip(), "the failure row must be VISIBLE prose, never blank" + assert "engine_logged" not in row, ( + "the failure row must NOT be engine_logged — the client would hide it (app.jsx drops " + "engine_logged rows in favor of /events, where this row never lands)" + ) + + +def test_record_dm_reply_whitespace_only_is_blank(tmp_path): + chat = tmp_path / "chat.jsonl" + script = _hdr(tmp_path, chat) + 'record_dm_reply "" " " beat\n' + r = _bash(script) + assert r.returncode == 0, r.stderr + rows = _chat_rows(chat) + assert len(rows) == 1 and rows[0].get("beat_failed") is True, rows + + +def test_record_dm_reply_nonblank_path_unchanged(tmp_path): + """The legacy non-blank path stays byte-identical (the engine-log-failure branch here).""" + chat = tmp_path / "chat.jsonl" + script = _hdr(tmp_path, chat) + f'record_dm_reply "" {PROSE_1!r} beat\n' + r = _bash(script) + assert r.returncode == 0, r.stderr + assert _chat_rows(chat) == [{"role": "dm", "text": PROSE_1}] + + +def test_failure_row_helper_shape_and_consume_once(tmp_path): + """clawdnd_chatlog_dm_failed: stamps beat_failed (never fallback_recovered, even when the + resolve flag was set) and consumes the resolve flags so the NEXT row is unflagged.""" + chat = tmp_path / "chat.jsonl" + script = ( + _hdr(tmp_path, chat) + + "CLAWDND_FALLBACK_RECOVERED=1\nCLAWDND_DM_BEAT_FAILED=1\n" + + "clawdnd_chatlog_dm_failed\n" + + f"clawdnd_chatlog_dm {PROSE_2!r}\n" + + 'printf "post_failed=%s post_recovered=%s\\n" "$CLAWDND_DM_BEAT_FAILED" "$CLAWDND_FALLBACK_RECOVERED"\n' + ) + r = _bash(script) + assert r.returncode == 0, r.stderr + rows = _chat_rows(chat) + assert rows[0].get("beat_failed") is True and "fallback_recovered" not in rows[0], rows + assert rows[1] == {"role": "dm", "text": PROSE_2}, ( + f"the failure helper must consume the resolve flags: {rows}" + ) + assert "post_failed=0 post_recovered=0" in r.stdout + + +def test_failure_text_never_pollutes_engine_memory(tmp_path): + """The failure beat is chat-only BY DESIGN: nothing may land in the engine session log + (recap/FTS/lean-tail story memory + the next beat's #357 fallback all read it).""" + log = _seed_campaign(tmp_path, [PROSE_1]) + before = log.read_text(encoding="utf-8") + chat = tmp_path / "chat.jsonl" + r = _bash(_hdr(tmp_path, chat) + 'record_dm_reply "c1" "" beat\n') + assert r.returncode == 0, r.stderr + assert log.read_text(encoding="utf-8") == before, ( + "the failure beat must NOT be written to the engine session log" + ) + assert _chat_rows(chat)[0].get("beat_failed") is True + + +# ── leg 3: the chatlog overrides are deleted (the lib is the single implementation) ────────── + + +def test_runner_chatlog_overrides_deleted(): + """F12-7: qa/run_duo.sh:135, qa/ui_playtest.sh:138, qa/run_party.sh:169 each re-defined a + 3-arg chatlog AFTER sourcing the lib, silently discarding clawdnd_chatlog_dm's honesty + stamp. The shared lib chatlog (a verified drop-in superset — it reads ambient $CHAT at call + time and writes a byte-identical row with no 3rd arg) must be the ONLY implementation.""" + override = re.compile(r"(?m)^\s*(function\s+)?chatlog\s*\(\)") + for rel in QA_RUNNERS: + src = (REPO_ROOT / rel).read_text(encoding="utf-8") + assert "lib_beat_driver.sh" in src, f"{rel} must source the shared lib" + assert not override.search(src), ( + f"{rel} re-defines chatlog() after sourcing the lib — the override shadows the " + f"shared 3-arg chatlog and kills the fallback_recovered/beat_failed stamps" + ) + assert "clawdnd_chatlog_dm" in src, f"{rel} must write dm rows via the shared helper" + + +def test_dm_wrappers_classify_and_mark(): + """Every DM-driving wrapper routes its final-text extraction through the shared + classification front door and takes the pre-beat mark (once per beat, before attempt 1).""" + for rel in ALL_DM_WRAPPERS: + src = (REPO_ROOT / rel).read_text(encoding="utf-8") + assert "clawdnd_dm_final_text" in src, f"{rel} must extract via clawdnd_dm_final_text" + assert "clawdnd_dm_prebeat_mark" in src, f"{rel} must take the pre-beat log-tail mark" + for rel in QA_RUNNERS: + src = (REPO_ROOT / rel).read_text(encoding="utf-8") + assert "clawdnd_chatlog_dm_failed" in src, ( + f"{rel} must record the visible failure beat on a failed/blank DM beat" + ) + + +def test_lib_chatlog_three_arg_contract_for_runners(tmp_path): + """The lib chatlog the runners now inherit: 2-arg rows byte-identical to the old override; + 3-arg rows merge the extra JSON (the stamp path the overrides were killing).""" + chat = tmp_path / "chat.jsonl" + script = ( + _hdr(tmp_path, chat) + + f"chatlog player {PROSE_1!r}\n" + + "CLAWDND_FALLBACK_RECOVERED=1\n" + + f"clawdnd_chatlog_dm {PROSE_2!r}\n" + ) + r = _bash(script) + assert r.returncode == 0, r.stderr + rows = _chat_rows(chat) + assert rows[0] == {"role": "player", "text": PROSE_1} + assert rows[1] == {"role": "dm", "text": PROSE_2, "fallback_recovered": True} + + +# ── leg 3: the assert_behavioral consumer (count + report; no gate flip) ───────────────────── + + +def _minimal_green_run(tmp_path) -> tuple[Path, Path]: + run = tmp_path / "run.jsonl" + run.write_text( + json.dumps( + { + "type": "assistant", + "message": { + "content": [ + {"type": "text", "text": "The scene unfolds."}, + {"type": "tool_use", "name": "mcp__clawdnd-engine__roll", + "id": "t1", "input": {}}, + ] + }, + } + ) + + "\n", + encoding="utf-8", + ) + state = tmp_path / "state.json" + state.write_text( + json.dumps({"characters": {"p1": {"kind": "player"}}, "party": ["p1"]}), + encoding="utf-8", + ) + return run, state + + +def test_assert_behavioral_counts_and_reports_stamps_without_gating(tmp_path): + """The fallback_recovered/beat_failed consumer: counted + reported on every gate run, but + NEVER flips RED by itself (the discount/gate policy stays #757's call).""" + run, state = _minimal_green_run(tmp_path) + chat = tmp_path / "chat.jsonl" + chat.write_text( + "\n".join( + json.dumps(r) + for r in [ + {"role": "player", "text": "[say] hello"}, + {"role": "dm", "text": "A fine evening."}, + {"role": "dm", "text": "(The tale falters...)", "beat_failed": True}, + {"role": "dm", "text": PROSE_1, "fallback_recovered": True}, + ] + ) + + "\n", + encoding="utf-8", + ) + r = subprocess.run( + [sys.executable, str(REPO_ROOT / "qa" / "assert_behavioral.py"), + str(run), str(state), str(chat)], + capture_output=True, text=True, cwd=str(REPO_ROOT), + ) + assert r.returncode == 0, f"the honesty counters must not flip the gate: {r.stdout}\n{r.stderr}" + assert "dm_beat_honesty" in r.stdout + assert "beats_failed=1" in r.stdout, r.stdout + assert "fallback_recovered=1" in r.stdout, r.stdout + assert "[WARN] dm_beat_honesty" in r.stdout, "counts surface as a WARN, never a FAIL" + + +def test_assert_behavioral_honesty_passes_clean_run(tmp_path): + run, state = _minimal_green_run(tmp_path) + chat = tmp_path / "chat.jsonl" + chat.write_text( + json.dumps({"role": "player", "text": "[say] hi"}) + "\n" + + json.dumps({"role": "dm", "text": "Welcome."}) + "\n", + encoding="utf-8", + ) + r = subprocess.run( + [sys.executable, str(REPO_ROOT / "qa" / "assert_behavioral.py"), + str(run), str(state), str(chat)], + capture_output=True, text=True, cwd=str(REPO_ROOT), + ) + assert r.returncode == 0, r.stdout + assert "[PASS] dm_beat_honesty" in r.stdout, r.stdout + + +# ── hygiene: every touched script stays /bin/bash -n clean (macOS bash 3.2) ────────────────── + + +@pytest.mark.parametrize("rel", list(ALL_DM_WRAPPERS) + ["qa/lib_beat_driver.sh"]) +def test_touched_scripts_parse_under_bin_bash(rel): + r = subprocess.run(["/bin/bash", "-n", str(REPO_ROOT / rel)], + capture_output=True, text=True) + assert r.returncode == 0, f"{rel} failed bash -n: {r.stderr}"