feat(recording): link session observations proposals and action results
Capture all successful state reads with hashes and session-local IDs. Record action intent before POST, retain accepted/rejected/unknown results, and link subsequent observations. Preserve legacy feeds and finalize each invocation synchronously.
This commit is contained in:
parent
ba519a850e
commit
9696282110
10 changed files with 476 additions and 123 deletions
201
run.py
201
run.py
|
|
@ -15,20 +15,19 @@ usage:
|
|||
from __future__ import annotations
|
||||
|
||||
import argparse
|
||||
import atexit
|
||||
import json
|
||||
import math
|
||||
import os
|
||||
import pathlib
|
||||
import sys
|
||||
import time
|
||||
import uuid
|
||||
|
||||
import brain
|
||||
import facts as F
|
||||
import sts2
|
||||
from jev import JevClient, JevError, answer_record
|
||||
from run_state import RunContext
|
||||
from recording import SessionRecorder
|
||||
|
||||
# Where the game writes its own run records. This is the OUTCOME source: it
|
||||
# carries win/loss, the killer, the seed and the final deck. Override with
|
||||
|
|
@ -38,14 +37,6 @@ HISTORY_DIR = pathlib.Path(os.environ.get(
|
|||
"~/Library/Application Support/SlayTheSpire2/steam/"
|
||||
"76561198141226155/modded/profile1/saves/history")).expanduser()
|
||||
|
||||
# One id per process, written into every trace row. A decision row and the model
|
||||
# answers that produced it must be joinable, and a bare wall-clock time is not
|
||||
# an identifier: JEV_TRACE timestamps only to the second, so several calls share
|
||||
# a timestamp and nothing in it names the run, step or action. The random suffix
|
||||
# keeps two processes started in the same second apart.
|
||||
SESSION_ID = f"{time.strftime('%Y%m%dT%H%M%S')}-{uuid.uuid4().hex[:6]}"
|
||||
|
||||
|
||||
class RecordingClient:
|
||||
"""
|
||||
Wraps a JevClient so the last call's questions and answers travel with the
|
||||
|
|
@ -66,6 +57,7 @@ class RecordingClient:
|
|||
def __init__(self, inner: JevClient) -> None:
|
||||
self._inner = inner
|
||||
self.last: dict | None = None
|
||||
self.last_request: dict | None = None
|
||||
|
||||
@property
|
||||
def model(self) -> str:
|
||||
|
|
@ -75,13 +67,16 @@ class RecordingClient:
|
|||
return f"RecordingClient({self._inner!r})"
|
||||
|
||||
def ask(self, state, questions, model=None):
|
||||
self.last_request = {"state": state, "questions": questions, "model": model or self.model}
|
||||
response = self._inner.ask(state, questions, model)
|
||||
self.last = {
|
||||
"state": state,
|
||||
"model": response.model,
|
||||
"latency_s": round(response.latency_s, 3),
|
||||
"questions": questions,
|
||||
"answers": {qid: answer_record(a)
|
||||
for qid, a in response.answers.items()},
|
||||
"answer_gate_scope": "default_helper_not_policy_gate",
|
||||
}
|
||||
return response
|
||||
|
||||
|
|
@ -114,40 +109,16 @@ def run_outcome(name: str) -> dict:
|
|||
}
|
||||
|
||||
|
||||
def session_record(session_id: str, started_at: str, ended_at: str, steps: int,
|
||||
sources: dict, produced) -> dict:
|
||||
"""
|
||||
session id -> the run record(s) that session produced.
|
||||
|
||||
Nothing else writes this mapping: the game's history file does not know our
|
||||
session id, and the A/B harness only maps a policy to a filename. Without it
|
||||
a decision cannot be attributed to the run it belongs to, so no arm-level
|
||||
outcome analysis (A/B, delayed reward) is possible.
|
||||
|
||||
It is NOT a per-decision accuracy label. One run result attached to a step
|
||||
says nothing about whether that step's answer was correct; calibrating a
|
||||
gate needs labels for the individual answers.
|
||||
"""
|
||||
return {
|
||||
"session": session_id,
|
||||
"started": started_at,
|
||||
"ended": ended_at,
|
||||
"steps": steps,
|
||||
"sources": sources,
|
||||
"runs": [run_outcome(name) for name in sorted(produced)],
|
||||
}
|
||||
|
||||
|
||||
def decision_record(step: int, state_type: str, run_state, decision,
|
||||
error: str | None, client) -> dict:
|
||||
error: str | None, client, *, session_id: str) -> dict:
|
||||
"""
|
||||
One JSONL row per decided action, carrying the model's answers with it.
|
||||
Shared payload for a proposal and its compatible `decide` feed row.
|
||||
|
||||
`jev` is None for a decision that did not ask the model (code paths and
|
||||
fallbacks), so an absent entry is a fact about the decision, not a gap.
|
||||
"""
|
||||
return {
|
||||
"session": SESSION_ID,
|
||||
"session": session_id,
|
||||
"step": step,
|
||||
"state_type": state_type,
|
||||
"run": run_state,
|
||||
|
|
@ -166,7 +137,7 @@ def observe() -> dict:
|
|||
return sts2.state()
|
||||
|
||||
|
||||
def preflight(obs: dict, *, dry_run: bool = False) -> str | None:
|
||||
def preflight(obs: dict, *, dry_run: bool = False, act=None) -> str | None:
|
||||
"""
|
||||
Detect states the bot cannot proceed from, so a session does not silently
|
||||
burn its whole step budget doing nothing.
|
||||
|
|
@ -181,7 +152,7 @@ def preflight(obs: dict, *, dry_run: bool = False) -> str | None:
|
|||
if dry_run:
|
||||
return None
|
||||
try:
|
||||
result = sts2.act("menu_select", option="main_menu")
|
||||
result = (act or sts2.act)("menu_select", option="main_menu")
|
||||
if not result.ok:
|
||||
return f"BLOCKED: game-over dismissal rejected: {result.message}"
|
||||
# The dismissal is not instant. Without this wait the loop reads the
|
||||
|
|
@ -250,26 +221,90 @@ def main() -> int:
|
|||
if not math.isfinite(args.stuck_seconds) or args.stuck_seconds <= 0:
|
||||
ap.error("stuck-seconds must be finite and positive")
|
||||
|
||||
try:
|
||||
with SessionRecorder(args.capture_dir, dry_run=args.dry_run) as recording:
|
||||
history_before = history_snapshot()
|
||||
try:
|
||||
return _run_session(args, recording)
|
||||
finally:
|
||||
try:
|
||||
recording.summary["runs"] = [run_outcome(name) for name in sorted(history_snapshot() - history_before)]
|
||||
except Exception as exc: # Outcome attribution must not mask the session's actual exit.
|
||||
recording.summary.update(runs=[], outcome_error=f"{type(exc).__name__}: {str(exc)[:200]}")
|
||||
except KeyboardInterrupt:
|
||||
print("interrupted; session recording finalized")
|
||||
return 130
|
||||
except OSError as exc:
|
||||
print(f"recording failed; stopping without another action: {exc}")
|
||||
return 1
|
||||
|
||||
|
||||
def _run_session(args, recording: SessionRecorder) -> int:
|
||||
stats = recording.sources
|
||||
started = time.monotonic()
|
||||
step = waits = 0
|
||||
run_context = RunContext()
|
||||
# Grepped by ab_card_skip.sh for attribution. New for every main() call.
|
||||
print(f"session: {recording.session_id}")
|
||||
|
||||
def trace(record: dict) -> None:
|
||||
record.setdefault("observation_id", recording.observation_id)
|
||||
recording.write(record)
|
||||
|
||||
def finish(code: int, reason: str) -> int:
|
||||
elapsed = time.monotonic() - started
|
||||
print(f"steps={step} waits={waits} elapsed={elapsed:.1f}s sources={stats} "
|
||||
f"stop={reason} exit={code}")
|
||||
return recording.finish(code, reason)
|
||||
|
||||
def read_observation(phase: str = "loop") -> dict:
|
||||
observation = observe()
|
||||
recording.observe(observation, step=step, phase=phase)
|
||||
return observation
|
||||
|
||||
def propose(observation, decision, error=None, client=None):
|
||||
record = decision_record(step, observation.get("state_type"), observation.get("run"),
|
||||
decision, error, client, session_id=recording.session_id)
|
||||
record.update(run_id=run_context.run_id, run_seed=run_context.seed,
|
||||
deck_provenance=(run_context.deck or {}).get("provenance"),
|
||||
observation_id=recording.observation_id)
|
||||
proposal_id = recording.propose(record)
|
||||
record["proposal_id"] = proposal_id
|
||||
return record, proposal_id
|
||||
|
||||
def system_action(observation, action, params, reason):
|
||||
decision = brain.Decision(action, params, reason, "code")
|
||||
record, proposal_id = propose(observation, decision)
|
||||
trace(record)
|
||||
stats["code"] += 1
|
||||
if args.dry_run:
|
||||
recording.disposition(proposal_id, "dry_run")
|
||||
return None
|
||||
return recording.execute(proposal_id, decision, sts2.act)
|
||||
|
||||
if not sts2.is_up():
|
||||
print(f"game not reachable at {sts2.BASE}")
|
||||
return 1
|
||||
return finish(1, "startup_error")
|
||||
|
||||
# Fail fast on a state the bot cannot leave, instead of burning the whole
|
||||
# step budget on rejected actions.
|
||||
try:
|
||||
blocker = preflight(observe(), dry_run=args.dry_run)
|
||||
obs = read_observation("preflight")
|
||||
if args.dry_run and obs.get("state_type") == "game_over":
|
||||
system_action(obs, "menu_select", {"option": "main_menu"}, "preflight game-over dismissal")
|
||||
blocker = preflight(obs, dry_run=args.dry_run,
|
||||
act=lambda action, **params: system_action(obs, action, params, "preflight game-over dismissal"))
|
||||
except sts2.Sts2Error as exc:
|
||||
trace({"event": "observation_error", "step": step, "phase": "preflight", "error": str(exc)[:160]})
|
||||
print(f"cannot read state: {exc}")
|
||||
return 1
|
||||
return finish(1, "startup_error")
|
||||
if blocker:
|
||||
print(blocker)
|
||||
return 2
|
||||
return finish(2, "preflight_blocked")
|
||||
|
||||
if args.card_skip_policy:
|
||||
brain.CARD_SKIP_POLICY = args.card_skip_policy
|
||||
print(f"card skip policy: {brain.CARD_SKIP_POLICY}")
|
||||
# Grepped by ab_card_skip.sh to stamp its attribution rows with the same id.
|
||||
print(f"session: {SESSION_ID}")
|
||||
|
||||
client = None
|
||||
if not args.no_jev:
|
||||
|
|
@ -278,58 +313,8 @@ def main() -> int:
|
|||
print(f"jev ready: {client!r}")
|
||||
except JevError as exc:
|
||||
print(f"jev unavailable: {exc}; use --no-jev for an intentional heuristic session")
|
||||
return 3
|
||||
return finish(3, "model_initialization")
|
||||
|
||||
capdir = pathlib.Path(args.capture_dir)
|
||||
capdir.mkdir(parents=True, exist_ok=True)
|
||||
trace_path = capdir / "decisions.jsonl"
|
||||
|
||||
def trace(record: dict) -> None:
|
||||
# One JSON line per decided action. Tail it while the bot plays:
|
||||
# tail -f capture/decisions.jsonl | jq
|
||||
record["ts"] = time.strftime("%H:%M:%S")
|
||||
record.setdefault("session", SESSION_ID)
|
||||
with trace_path.open("a", encoding="utf-8") as fh:
|
||||
fh.write(json.dumps(record, sort_keys=True, default=str) + "\n")
|
||||
|
||||
stats = {"code": 0, "jev": 0, "fallback": 0}
|
||||
started = time.monotonic()
|
||||
|
||||
# The outcome half of the join: which run record(s) this session produced.
|
||||
# Registered with atexit so EVERY exit path writes it -- the normal end, the
|
||||
# step cap, a stuck screen, a model-failure abort, or an exception.
|
||||
history_before = history_snapshot()
|
||||
step = 0
|
||||
exit_code = 1
|
||||
stop_reason = "interrupted"
|
||||
started_at = time.strftime("%Y-%m-%dT%H:%M:%S")
|
||||
|
||||
def write_session_row() -> None:
|
||||
try:
|
||||
row = session_record(SESSION_ID, started_at,
|
||||
time.strftime("%Y-%m-%dT%H:%M:%S"), step, stats,
|
||||
history_snapshot() - history_before)
|
||||
row.update(exit_code=exit_code, stop_reason=stop_reason, dry_run=args.dry_run)
|
||||
with (capdir / "sessions.jsonl").open("a", encoding="utf-8") as fh:
|
||||
fh.write(json.dumps(row, sort_keys=True, default=str) + "\n")
|
||||
except OSError:
|
||||
pass # bookkeeping must never break the exit
|
||||
|
||||
def finish(code: int, reason: str) -> int:
|
||||
nonlocal exit_code, stop_reason
|
||||
exit_code, stop_reason = code, reason
|
||||
trace({"event": "session_end", "step": step, "exit_code": code, "reason": reason})
|
||||
elapsed = time.monotonic() - started
|
||||
print(f"steps={step} waits={waits} elapsed={elapsed:.1f}s sources={stats} "
|
||||
f"stop={reason} exit={code}")
|
||||
return code
|
||||
|
||||
atexit.register(write_session_row)
|
||||
|
||||
# Never load the old unscoped deck.json. Visible combat piles are limited
|
||||
# evidence, not a persistent deck, and remain local to this session/run.
|
||||
run_context = RunContext()
|
||||
waits = 0
|
||||
rejected = 0
|
||||
last_sig: str | None = None
|
||||
same_state = 0
|
||||
|
|
@ -343,9 +328,11 @@ def main() -> int:
|
|||
pending_since = time.monotonic()
|
||||
|
||||
for step in range(1, args.steps + 1):
|
||||
recording.step = step
|
||||
try:
|
||||
obs = observe()
|
||||
obs = read_observation()
|
||||
except sts2.Sts2Error as exc:
|
||||
trace({"event": "observation_error", "step": step, "phase": "loop", "error": str(exc)[:160]})
|
||||
print(f"[{step:03d}] state read failed: {str(exc)[:160]}")
|
||||
return finish(1, "state_error")
|
||||
|
||||
|
|
@ -384,10 +371,11 @@ def main() -> int:
|
|||
if args.stop_on_run_end and st == "game_over":
|
||||
if args.dry_run:
|
||||
print(f"[{step:03d}] dry run: would dismiss game-over")
|
||||
system_action(obs, "menu_select", {"option": "main_menu"}, "run-end dismissal")
|
||||
return finish(0, "run_end_preview")
|
||||
print(f"[{step:03d}] run ended; dismissing game-over, then stopping")
|
||||
try:
|
||||
result = sts2.act("menu_select", option="main_menu")
|
||||
result = system_action(obs, "menu_select", {"option": "main_menu"}, "run-end dismissal")
|
||||
except sts2.Sts2Error as exc:
|
||||
print(f"[{step:03d}] could not dismiss game-over: {exc}")
|
||||
return finish(1, "dismiss_error")
|
||||
|
|
@ -437,7 +425,6 @@ def main() -> int:
|
|||
|
||||
if st in ("monster", "elite", "boss"):
|
||||
f = F.combat_facts(obs)
|
||||
(capdir / f"live_{step:03d}_combat.json").write_text(json.dumps(obs, indent=2))
|
||||
print(f"[{step:03d}] COMBAT {f.describe().splitlines()[0]}")
|
||||
for line in f.describe().splitlines()[1:]:
|
||||
print(f" {line}")
|
||||
|
|
@ -449,6 +436,7 @@ def main() -> int:
|
|||
# Cleared first: a decision that asks nothing (code paths, fallbacks)
|
||||
# must not inherit the previous step's answers in the log.
|
||||
client.last = None
|
||||
client.last_request = None
|
||||
try:
|
||||
decision = brain.decide(obs, client, run_context.deck, context=policy_context)
|
||||
# A procedural action or animation wait does not establish model
|
||||
|
|
@ -460,7 +448,7 @@ def main() -> int:
|
|||
print(f"[{step:03d}] jev error ({jev_errors}): {str(exc)[:140]}")
|
||||
decide_error = f"JevError: {str(exc)[:160]}"
|
||||
trace({"step": step, "event": "model_error", "error": decide_error,
|
||||
"consecutive_failures": jev_errors})
|
||||
"consecutive_failures": jev_errors, "request": getattr(client, "last_request", None)})
|
||||
if jev_errors >= args.max_jev_errors:
|
||||
print(f"[{step:03d}] ABORT: {jev_errors} consecutive model failures. "
|
||||
f"The run would continue on heuristics alone, which is not "
|
||||
|
|
@ -491,15 +479,19 @@ def main() -> int:
|
|||
print(json.dumps(obs, indent=2)[:800])
|
||||
return finish(1, "no_decision")
|
||||
|
||||
record, proposal_id = propose(obs, decision, decide_error, client)
|
||||
|
||||
# Bound unresolved actions even if unrelated observation fields change.
|
||||
if policy_context.pending is not pending_action:
|
||||
pending_action = policy_context.pending
|
||||
pending_since = time.monotonic()
|
||||
if pending_action is not None and time.monotonic() - pending_since > args.stuck_seconds:
|
||||
recording.disposition(proposal_id, "session_stopped")
|
||||
return finish(1, "pending_action_timeout")
|
||||
|
||||
# Between turns there is nothing to do but look again.
|
||||
if decision.action == "__wait__":
|
||||
recording.disposition(proposal_id, "wait")
|
||||
waits += 1
|
||||
print(f"[{step:03d}] WAIT {decision.reason}")
|
||||
time.sleep(args.pause)
|
||||
|
|
@ -518,6 +510,7 @@ def main() -> int:
|
|||
if same_state > 0 and last_ok and action_key == last_action_key:
|
||||
duplicate_waits += 1
|
||||
if duplicate_waits <= args.max_duplicate_waits:
|
||||
recording.disposition(proposal_id, "suppressed")
|
||||
waits += 1
|
||||
print(f"[{step:03d}] WAIT same action on unchanged state ({same_state})")
|
||||
time.sleep(args.pause)
|
||||
|
|
@ -528,17 +521,15 @@ def main() -> int:
|
|||
|
||||
stats[decision.source] = stats.get(decision.source, 0) + 1
|
||||
print(f"[{step:03d}] DECIDE {decision}")
|
||||
record = decision_record(step, st, obs.get("run"), decision, decide_error, client)
|
||||
record.update(run_id=run_context.run_id, run_seed=run_context.seed,
|
||||
deck_provenance=(run_context.deck or {}).get("provenance"))
|
||||
trace(record)
|
||||
last_action_key = action_key
|
||||
|
||||
if args.dry_run:
|
||||
recording.disposition(proposal_id, "dry_run")
|
||||
continue
|
||||
|
||||
last_action_key = action_key
|
||||
try:
|
||||
result = sts2.act(decision.action, **decision.params)
|
||||
result = recording.execute(proposal_id, decision, sts2.act)
|
||||
except sts2.Sts2Error as exc:
|
||||
print(f"[{step:03d}] action failed: {str(exc)[:200]}")
|
||||
trace({"step": step, "event": "action_error",
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue