diff --git a/routes/lab.py b/routes/lab.py index fd6175c..576ffa8 100644 --- a/routes/lab.py +++ b/routes/lab.py @@ -39,6 +39,7 @@ from services.deck_service import parse_dck_file, _load_deck_cards_by_name from services.forge_runner import ( build_java_command, run_batch_subprocess, _run_deepseek_batch_thread, ) +from services.draw_game_analyzer import summarize_draw_games from services.logging import log, log_batch router = APIRouter(tags=["lab"]) @@ -223,14 +224,18 @@ async def get_result(batchId: Optional[str] = None): except (json.JSONDecodeError, OSError) as e: raise HTTPException(500, f"Failed to read result file: {e}") - # ── Inject winType into every game dict (fix #180) ────────────────────── - # win_type_override is set by forge_runner._run_process_blocking() for the - # Java/Forge path. DeepSeek games already have per-game winType stamped - # directly in the result dict; _inject_win_type uses setdefault so those - # are never overwritten. + # ── Inject winType into every game dict (fix #175) ────────────────────── win_type_override = getattr(state, "win_type_override", "Combat") _inject_win_type(data, win_type_override) + # ── Inject draw-game summary (fix #176) ───────────────────────────────── + # draw_game_snapshots is populated live by forge_runner._run_process_blocking + # from [DRAW] [PARSE-SUMMARY] lines. summarize_draw_games() aggregates them + # into a single dict with perDeck breakdowns and a likelyCause field so the + # dashboard can immediately show which deck is causing timeout loops. + draw_snapshots = getattr(state, "draw_game_snapshots", []) + data["drawGames"] = summarize_draw_games(draw_snapshots) + data = _sanitize_floats(data) return JSONResponse(content=data) @@ -304,31 +309,31 @@ async def list_history(): AI_PROFILES = { "default": { "name": "default", - "description": "Balanced \u2014 Forge's default AI behavior", + "description": "Balanced — Forge's default AI behavior", "aggression": 0.5, "cardAdvantage": 0.5, "removalPriority": 0.5, "boardPresence": 0.5, "comboPriority": 0.3, "patience": 0.5, }, "aggro": { "name": "aggro", - "description": "Aggressive \u2014 attacks early, prioritizes damage", + "description": "Aggressive — attacks early, prioritizes damage", "aggression": 0.9, "cardAdvantage": 0.3, "removalPriority": 0.3, "boardPresence": 0.8, "comboPriority": 0.1, "patience": 0.1, }, "control": { "name": "control", - "description": "Control \u2014 defensive, removal-heavy, card advantage", + "description": "Control — defensive, removal-heavy, card advantage", "aggression": 0.2, "cardAdvantage": 0.9, "removalPriority": 0.9, "boardPresence": 0.3, "comboPriority": 0.4, "patience": 0.9, }, "combo": { "name": "combo", - "description": "Combo \u2014 ramps, digs for pieces, assembles combos", + "description": "Combo — ramps, digs for pieces, assembles combos", "aggression": 0.2, "cardAdvantage": 0.8, "removalPriority": 0.4, "boardPresence": 0.3, "comboPriority": 0.95, "patience": 0.7, }, "midrange": { "name": "midrange", - "description": "Midrange \u2014 flexible, strong board presence, value-oriented", + "description": "Midrange — flexible, strong board presence, value-oriented", "aggression": 0.5, "cardAdvantage": 0.6, "removalPriority": 0.6, "boardPresence": 0.7, "comboPriority": 0.3, "patience": 0.5, }, diff --git a/services/draw_game_analyzer.py b/services/draw_game_analyzer.py new file mode 100644 index 0000000..ddfcc7c --- /dev/null +++ b/services/draw_game_analyzer.py @@ -0,0 +1,152 @@ +""" +services/draw_game_analyzer.py +============================== +Analyses draw-game snapshots captured by forge_runner._run_process_blocking. + +A "draw game" is any game that hit the Forge per-game wall-clock timeout +instead of ending via a win condition. Forge emits a line like: + + [DRAW] [PARSE-SUMMARY] game=42 turns=28 time_ms=61200 \ + seat0=AdaptiveEnchantment:life=46 seat1=AbzanArmor:life=0 \ + seat2=AhoyMateys:life=0 seat3=20WaysToWin:life=8 + +This module: + 1. Parses those lines out of the log into DrawGameSnapshot objects. + 2. Aggregates them to identify which deck most often leads at timeout. + 3. Exposes a summary dict suitable for embedding in the batch result JSON. +""" +from __future__ import annotations + +import re +from dataclasses import dataclass, field +from typing import Dict, List, Optional + + +# ─── regex for the Forge DRAW summary line ──────────────────────────────────── +# Example: +# [DRAW] [PARSE-SUMMARY] game=42 turns=28 time_ms=61200 +# seat0=AdaptiveEnchantment:life=46 seat1=AbzanArmor:life=0 +# seat2=AhoyMateys:life=0 seat3=20WaysToWin:life=8 +_DRAW_LINE_RE = re.compile( + r'\[DRAW\].*?\[PARSE-SUMMARY\]' + r'.*?game=(\d+)' + r'.*?turns=(\d+)' + r'.*?time_ms=(\d+)' + r'((?:\s+seat\d+=\S+)*)' + , re.IGNORECASE +) +_SEAT_RE = re.compile(r'seat(\d+)=([^:]+):life=([-\d]+)', re.IGNORECASE) + + +@dataclass +class DrawGameSnapshot: + game_id: int + turns: int + time_ms: int + # seat_index -> {deck_name, life} + seats: Dict[int, dict] = field(default_factory=dict) + + @property + def leading_deck(self) -> Optional[str]: + """Name of the deck with the highest life at timeout (None if tie/empty).""" + if not self.seats: + return None + best = max(self.seats.values(), key=lambda s: s["life"]) + return best["deck_name"] + + @property + def leading_life(self) -> int: + if not self.seats: + return 0 + return max(s["life"] for s in self.seats.values()) + + +def parse_draw_snapshots(log_lines: list[str]) -> list[DrawGameSnapshot]: + """ + Scan raw log lines for [DRAW] [PARSE-SUMMARY] entries and return + a list of DrawGameSnapshot objects, one per draw game. + """ + snapshots: list[DrawGameSnapshot] = [] + for line in log_lines: + m = _DRAW_LINE_RE.search(line) + if not m: + continue + game_id = int(m.group(1)) + turns = int(m.group(2)) + time_ms = int(m.group(3)) + seats_str = m.group(4) or "" + seats: Dict[int, dict] = {} + for sm in _SEAT_RE.finditer(seats_str): + seat_idx = int(sm.group(1)) + deck_name = sm.group(2).strip() + life = int(sm.group(3)) + seats[seat_idx] = {"deck_name": deck_name, "life": life} + snapshots.append(DrawGameSnapshot(game_id=game_id, turns=turns, time_ms=time_ms, seats=seats)) + return snapshots + + +def summarize_draw_games(snapshots: list[DrawGameSnapshot]) -> dict: + """ + Aggregate draw snapshots into a summary dict for embedding in batch JSON. + + Returns:: + + { + "count": 156, + "avgTurns": 27.4, + "avgTimeMs": 61800, + "perDeck": [ + { + "deckName": "AdaptiveEnchantment", + "drawLeadCount": 89, # times this deck led at timeout + "drawLeadPct": 57.1, + "avgLifeAtTimeout": 42.3, + }, + ... + ], + "likelyCause": "AdaptiveEnchantment" # deck most often leading at timeout + } + """ + if not snapshots: + return {"count": 0, "avgTurns": 0, "avgTimeMs": 0, "perDeck": [], "likelyCause": None} + + total = len(snapshots) + avg_turns = round(sum(s.turns for s in snapshots) / total, 1) + avg_time_ms = round(sum(s.time_ms for s in snapshots) / total) + + # Accumulate per-deck stats across all draw games + deck_lead_count: Dict[str, int] = {} + deck_life_sum: Dict[str, float] = {} + deck_life_count: Dict[str, int] = {} + + for snap in snapshots: + leader = snap.leading_deck + if leader: + deck_lead_count[leader] = deck_lead_count.get(leader, 0) + 1 + for seat in snap.seats.values(): + dn = seat["deck_name"] + deck_life_sum[dn] = deck_life_sum.get(dn, 0.0) + seat["life"] + deck_life_count[dn] = deck_life_count.get(dn, 0) + 1 + + all_decks = set(deck_life_count.keys()) | set(deck_lead_count.keys()) + per_deck = [] + for dn in sorted(all_decks): + lead_cnt = deck_lead_count.get(dn, 0) + avg_life = round(deck_life_sum.get(dn, 0) / max(deck_life_count.get(dn, 1), 1), 1) + per_deck.append({ + "deckName": dn, + "drawLeadCount": lead_cnt, + "drawLeadPct": round(lead_cnt / total * 100, 1), + "avgLifeAtTimeout": avg_life, + }) + + per_deck.sort(key=lambda x: x["drawLeadCount"], reverse=True) + likely_cause = per_deck[0]["deckName"] if per_deck else None + + return { + "count": total, + "avgTurns": avg_turns, + "avgTimeMs": avg_time_ms, + "perDeck": per_deck, + "likelyCause": likely_cause, + } diff --git a/services/forge_runner.py b/services/forge_runner.py index 2fc326c..cf82737 100644 --- a/services/forge_runner.py +++ b/services/forge_runner.py @@ -210,8 +210,44 @@ def build_java_command( return cmd +# ── Draw-game life-at-timeout parser ───────────────────────────────────────── +# Forge emits a summary line for each game that hits the wall-clock timeout: +# +# [DRAW] [PARSE-SUMMARY] game=42 turns=28 time_ms=61200 +# seat0=AdaptiveEnchantment:life=46 seat1=AbzanArmor:life=0 +# seat2=AhoyMateys:life=0 seat3=20WaysToWin:life=8 +# +# We capture these live so they're available before the process finishes. +_DRAW_SUMMARY_RE = re.compile( + r'\[DRAW\].*?\[PARSE-SUMMARY\]' + r'.*?game=(\d+)' + r'.*?turns=(\d+)' + r'.*?time_ms=(\d+)' + r'((?:\s+seat\d+=\S+)*)' + , re.IGNORECASE +) +_SEAT_LIFE_RE = re.compile(r'seat(\d+)=([^:]+):life=([-\d]+)', re.IGNORECASE) + + +def _parse_draw_summary_line(line: str) -> Optional[dict]: + """Return a draw-game snapshot dict if line matches, else None.""" + m = _DRAW_SUMMARY_RE.search(line) + if not m: + return None + seats = {} + for sm in _SEAT_LIFE_RE.finditer(m.group(4) or ""): + seat_idx = int(sm.group(1)) + seats[seat_idx] = {"deck_name": sm.group(2).strip(), "life": int(sm.group(3))} + return { + "game_id": int(m.group(1)), + "turns": int(m.group(2)), + "time_ms": int(m.group(3)), + "seats": seats, + } + + def _run_process_blocking(state: BatchState, cmd: list): - """Run Forge subprocess, parse progress, generate deck reports.""" + """Run Forge subprocess, parse progress, collect draw-game snapshots.""" log.info(f"Running: {' '.join(cmd)}") # Ensure Forge subprocesses use Java 17 @@ -237,10 +273,15 @@ def _run_process_blocking(state: BatchState, cmd: list): _register_batch(state.batch_id, state, proc) + # ── Live stdout parsing ─────────────────────────────────────────── + draw_snapshots: list = [] + for line in proc.stdout: _touch_batch(state.batch_id) line = line.rstrip() state.log_lines.append(line) + + # Progress counters gm = re.match(r'\[Game (\d+)/(\d+)\]', line) if gm: state.completed_games = int(gm.group(1)) @@ -249,13 +290,26 @@ def _run_process_blocking(state: BatchState, cmd: list): if pm: state.sims_per_sec = float(pm.group(1)) + # ── Draw-game capture (fix #176) ────────────────────────────── + snap = _parse_draw_summary_line(line) + if snap: + draw_snapshots.append(snap) + proc.wait() _unregister_batch(state.batch_id) elapsed = (_datetime.now() - state.start_time).total_seconds() * 1000 state.elapsed_ms = int(elapsed) + + # Persist draw snapshots on state for routes/lab.py to embed in JSON + state.draw_game_snapshots = draw_snapshots + if draw_snapshots: + log.info( + f"[DrawGames] Captured {len(draw_snapshots)} draw-game snapshots " + f"for batch {state.batch_id}" + ) + if proc.returncode != 0: state.running = False - # Include last few log lines in error for easier diagnosis tail = ' | '.join(state.log_lines[-5:]) if state.log_lines else '(no output)' state.error = f"Exit code {proc.returncode} — last output: {tail}" else: @@ -263,9 +317,6 @@ def _run_process_blocking(state: BatchState, cmd: list): state.completed_games = state.total_games # ── Post-process: detect alternate win conditions in the Java log ── - # Runs after the process exits so we don't slow the hot stdout loop. - # Stamps state.win_type_override which routes/lab_api.py can attach - # to each game result when building the batch JSON response. try: src_dir = os.path.join(os.path.dirname(os.path.abspath(__file__)), '..', 'src') src_dir = os.path.normpath(src_dir) @@ -286,7 +337,7 @@ async def run_batch_subprocess( num_games: int, threads: int, seed: Optional[int] = None, - clock: int = 6000, + clock: int = 3000, output_path: str = "results", use_learned_policy: bool = False, policy_style: str = "midrange", @@ -295,7 +346,12 @@ async def run_batch_subprocess( ai_think_time_ms: int = -1, max_queue_depth: int = -1, ): - """Async wrapper that runs Forge subprocess in executor.""" + """Async wrapper that runs Forge subprocess in executor. + + clock default lowered from 6000 → 3000 (30s per-game wall limit for batch + mode) to reduce draw-game wall time wasted on timeouts (fix #176). + Interactive games pass an explicit req.clock override so they are unaffected. + """ try: policy_server = f"http://localhost:{CFG.port}" cmd = build_java_command( @@ -523,17 +579,13 @@ def _run_deepseek_batch_thread( gd['gameNumber'] = g + 1 # ── Alternate win detection (DeepSeek path) ────────────── - # Inspect the winning player's battlefield for alternate-win - # permanents. result.winner is the seat index (0 = deck_a). try: winner_seat = result.winner_seat if winner_seat >= 0: - from commander_ai_lab.sim.game_state import get_final_battlefield winner_bf = getattr(result, '_winner_battlefield', None) if winner_bf is not None: win_type = detect_win_type_from_cards(winner_bf) else: - # Fallback: scan game_log lines if battlefield snapshot unavailable from commander_ai_lab.sim.win_condition_parser import detect_win_type_from_log win_type = detect_win_type_from_log( [str(entry) for entry in (result.game_log or [])]