diff --git a/scripts/run_scenario.py b/scripts/run_scenario.py index 7beef11..a82ec74 100644 --- a/scripts/run_scenario.py +++ b/scripts/run_scenario.py @@ -23,6 +23,7 @@ from rle.agents.social_overseer import SocialOverseer from rle.config import RLEConfig, bridge_anthropic_key, bridge_openrouter_key from rle.docker import wait_for_rimapi +from rle.orchestration.camera_director import CameraDirector from rle.orchestration.game_loop import RLEGameLoop from rle.rimapi.client import RimAPIClient from rle.rimapi.sse_client import RimAPISSEClient @@ -276,6 +277,13 @@ async def main(args: argparse.Namespace) -> None: except Exception as e: print(f"Setup command {cmd.type} failed: {e}") + camera_director = None + if args.camera_director: + camera_director = CameraDirector( + client, + output_dir=Path(args.output) if args.output else None, + ) + loop = RLEGameLoop( config, client, agents, expected_duration_days=scenario.expected_duration_days, @@ -292,6 +300,8 @@ async def main(args: argparse.Namespace) -> None: event_log=event_log, cost_tracker=cost_tracker, triggered_incidents=scenario.triggered_incidents, + auto_dismiss_dialogs=not args.no_dismiss_dialogs, + camera_director=camera_director, ) try: if visualizer: @@ -413,6 +423,16 @@ async def main(args: argparse.Namespace) -> None: "--no-pause", action="store_true", help="Don't pause game during deliberation (SSE-driven, game runs continuously)", ) + parser.add_argument( + "--camera-director", action="store_true", + help="Drive the game camera to the action each tick for cinematic " + "capture (writes camera_cues.jsonl to --output). Issue #34.", + ) + parser.add_argument( + "--no-dismiss-dialogs", action="store_true", + help="Don't auto-dismiss force-pause popups (colony-name dialog, debug " + "log). Dismissal is on by default for unattended runs. Issue #33.", + ) parser.add_argument( "--seed", type=int, default=None, help=( diff --git a/src/rle/agents/base_role.py b/src/rle/agents/base_role.py index 551f8fe..4f4704d 100644 --- a/src/rle/agents/base_role.py +++ b/src/rle/agents/base_role.py @@ -115,7 +115,8 @@ "- work_priority for EVERY colonist: best Plants→Growing=1, " "best Construction→Construction=1, best Intellectual→Research=1\n" "- growing_zone: use FARM SITE coordinates from MAP_SUMMARY, " - "plant_def=Plant_Rice (fastest food)\n\n" + "plant_def=Plant_Rice (fastest food). Create this zone ONCE — if a " + "growing zone already exists, do NOT create another (it will fail).\n\n" "TICK 2 (SHELTER — most critical):\n" "- blueprint Wall: place 5x5 rectangle using SHELTER SITE from MAP_SUMMARY. " "Use stuff_def=WoodLog. Leave one gap for a Door.\n" @@ -247,9 +248,49 @@ def _build_messages(self, system_prompt: str, user_prompt: str) -> list[ChatMess def _record_completion(self, result: CompletionResult) -> CompletionResult: self._last_raw_output = result.content - self._last_usage = result.usage if hasattr(result, "usage") else None + usage = dict(result.usage) if getattr(result, "usage", None) else None + if usage is not None: + # felix's usage dict only carries prompt/completion/total. Thinking + # models bill hidden reasoning tokens that OpenRouter/OpenAI report + # in usage.completion_tokens_details.reasoning_tokens but leave OUT + # of completion_tokens — dig them out of the raw response so the + # cost tracker can bill them (issue #33). + reasoning = self._extract_reasoning_tokens(getattr(result, "raw_response", None)) + if reasoning: + usage["reasoning_tokens"] = reasoning + self._last_usage = usage return result + @staticmethod + def _extract_reasoning_tokens(raw_response: Any) -> int: + """Pull reasoning-token count from a provider's raw usage payload. + + Handles both the OpenAI SDK object shape + (``usage.completion_tokens_details.reasoning_tokens``) and the plain + dict shape returned by OpenRouter / OpenAI-compatible servers. Returns + 0 when absent or unparseable — never raises. + """ + if raw_response is None: + return 0 + + def _get(obj: Any, key: str) -> Any: + if isinstance(obj, dict): + return obj.get(key) + return getattr(obj, key, None) + + usage = _get(raw_response, "usage") + if usage is None: + return 0 + details = _get(usage, "completion_tokens_details") + # Some servers attach reasoning_tokens directly on usage. + candidate = _get(details, "reasoning_tokens") if details is not None else None + if candidate is None: + candidate = _get(usage, "reasoning_tokens") + try: + return int(candidate) if candidate is not None else 0 + except (TypeError, ValueError): + return 0 + def _call_provider( self, system_prompt: str, diff --git a/src/rle/orchestration/action_executor.py b/src/rle/orchestration/action_executor.py index aff34e9..5f5b642 100644 --- a/src/rle/orchestration/action_executor.py +++ b/src/rle/orchestration/action_executor.py @@ -99,6 +99,22 @@ class ActionExecutor: def __init__(self, client: RimAPIClient) -> None: self._client = client + # Rectangles (x1, z1, x2, z2) of growing zones already created this run. + # Agents perseverate — they re-issue the same growing zone every tick. + # Each repeat targets cells already owned by the first zone, which RIMAPI + # rejects (and historically mislabelled as "Invalid plant definition"). + # We short-circuit overlapping repeats with an explicit error so the + # agent learns the zone exists instead of burning ticks on doomed calls + # (issue #33). + self._created_growing_zones: list[tuple[int, int, int, int]] = [] + + @staticmethod + def _rects_overlap( + a: tuple[int, int, int, int], b: tuple[int, int, int, int] + ) -> bool: + ax1, az1, ax2, az2 = a + bx1, bz1, bx2, bz2 = b + return not (ax2 < bx1 or ax1 > bx2 or az2 < bz1 or az1 > bz2) async def execute(self, plan: ActionPlan) -> ExecutionResult: """Execute all actions in a plan, return summary + per-action outcomes.""" @@ -232,10 +248,17 @@ async def _h_blueprint(self, cid: str, params: dict[str, Any]) -> None: ) async def _h_growing_zone(self, cid: str, params: dict[str, Any]) -> None: - x1 = params.get("x1", params.get("x", 0)) - z1 = params.get("z1", params.get("z", 0)) - x2 = params.get("x2", x1 + 5) - z2 = params.get("z2", z1 + 5) + x1 = int(params.get("x1", params.get("x", 0))) + z1 = int(params.get("z1", params.get("z", 0))) + x2 = int(params.get("x2", x1 + 5)) + z2 = int(params.get("z2", z1 + 5)) + rect = (min(x1, x2), min(z1, z2), max(x1, x2), max(z1, z2)) + if any(self._rects_overlap(rect, prev) for prev in self._created_growing_zones): + raise ValueError( + "A growing zone already covers these cells — it was created " + "earlier this run. Do NOT recreate it; pick a different, " + "non-overlapping rectangle or move on to another task." + ) await self._client.create_growing_zone( map_id=int(params.get("map_id", 0)), plant_def=params.get("plant_def", "Plant_Potato"), @@ -244,6 +267,7 @@ async def _h_growing_zone(self, cid: str, params: dict[str, Any]) -> None: x2=x2, z2=z2, ) + self._created_growing_zones.append(rect) async def _h_stockpile_zone(self, cid: str, params: dict[str, Any]) -> None: x1 = params.get("x1", params.get("x", 0)) diff --git a/src/rle/orchestration/camera_director.py b/src/rle/orchestration/camera_director.py new file mode 100644 index 0000000..94ec472 --- /dev/null +++ b/src/rle/orchestration/camera_director.py @@ -0,0 +1,245 @@ +"""Cinematic camera director — drives the RimWorld camera to the action. + +Issue #34: during a run the OBS/timelapse camera sat wherever it was left +(zoomed-out map center), so the events agents narrate — a raid, a colonist +bleeding out, a mental break — happened as a few pixels at the edge of frame. + +The director watches the same SSE event stream the agents see and eases the +camera to whatever is most story-worthy this tick: a downed/killed pawn, a +mental break, an incoming raid. Between events it drifts over the colony and +periodically zooms in on a colonist. Every decision is appended to a +camera-cue log (timestamp -> target) so the footage index can map video cuts +to camera moves. + +This is opt-in (capture runs only) and never raises into the game loop — a +missing camera endpoint or a malformed event degrades to a logged miss. +""" + +from __future__ import annotations + +import json +import logging +from pathlib import Path +from typing import TYPE_CHECKING, Any + +from pydantic import BaseModel, ConfigDict + +if TYPE_CHECKING: + from rle.rimapi.client import RimAPIClient + from rle.rimapi.schemas import GameState + from rle.rimapi.sse_client import RimAPIEvent + +logger = logging.getLogger(__name__) + +# Zoom levels (RimWorld CameraDriver: smaller = closer). +_ZOOM_CLOSEUP = 13 +_ZOOM_COLONY = 40 + +# SSE event types worth cutting to, highest priority first. A raid has no +# dedicated SSE type (it arrives as a letter / shows up in state.threats), so +# threats are handled separately from this table. +_EVENT_PRIORITY: tuple[str, ...] = ( + "pawn_killed", + "colonist_died", + "pawn_downed", + "colonist_mental_break", + "pawn_entered_map", +) + +# Candidate keys SSE payloads use for a pawn id / a map cell. RIMAPI's event +# shapes vary by Harmony hook, so we probe several rather than assume one. +_PAWN_ID_KEYS: tuple[str, ...] = ("pawn_id", "colonist_id", "thing_id", "victim_id") +_POS_KEYS: tuple[str, ...] = ("position", "pos", "location", "cell") + + +class CameraCue(BaseModel): + """One camera decision, logged for the footage index.""" + + model_config = ConfigDict(frozen=True) + + timestamp: float + tick: int + target_type: str # "pawn" | "cell" | "colony" + reason: str + pawn_id: str | None = None + x: int | None = None + z: int | None = None + zoom: int | None = None + + +class CameraDirector: + """Decides where the camera should look each tick and moves it there.""" + + def __init__( + self, + client: RimAPIClient, + *, + output_dir: Path | None = None, + drift_interval: int = 4, + ) -> None: + self._client = client + self._cue_log_path = ( + output_dir / "camera_cues.jsonl" if output_dir is not None else None + ) + self._drift_interval = max(1, drift_interval) + self.cues: list[CameraCue] = [] + + # -- target selection (pure, testable) ---------------------------------- + + @staticmethod + def _extract_pawn_id(data: dict[str, Any]) -> str | None: + for key in _PAWN_ID_KEYS: + value = data.get(key) + if value is not None and str(value) not in ("", "0"): + return str(value) + return None + + @staticmethod + def _extract_cell(data: dict[str, Any]) -> tuple[int, int] | None: + # Nested {"position": {"x": .., "z"/"y": ..}} or {"position": [x, z]}. + for key in _POS_KEYS: + pos = data.get(key) + if isinstance(pos, dict): + x = pos.get("x") + z = pos.get("z", pos.get("y")) + if isinstance(x, int) and isinstance(z, int): + return (x, z) + elif isinstance(pos, (list, tuple)) and len(pos) >= 2: + try: + return (int(pos[0]), int(pos[1])) + except (TypeError, ValueError): + continue + # Flat x/z on the event itself. + x_flat = data.get("x") + z_flat = data.get("z", data.get("y")) + if isinstance(x_flat, int) and isinstance(z_flat, int): + return (x_flat, z_flat) + return None + + def _select_event( + self, events: list[RimAPIEvent] + ) -> tuple[RimAPIEvent, int] | None: + """Pick the highest-priority event we can actually point the camera at.""" + best: tuple[RimAPIEvent, int] | None = None + for event in events: + if event.event_type not in _EVENT_PRIORITY: + continue + rank = _EVENT_PRIORITY.index(event.event_type) + if self._extract_pawn_id(event.data) is None and ( + self._extract_cell(event.data) is None + ): + continue + if best is None or rank < best[1]: + best = (event, rank) + return best + + # -- main entry point --------------------------------------------------- + + async def direct( + self, + tick: int, + state: GameState, + events: list[RimAPIEvent], + now: float, + ) -> CameraCue | None: + """Move the camera to this tick's focus and record the cue. + + ``now`` is passed in (rather than read here) so the caller controls the + clock and the cue log stays deterministic in tests. + """ + cue = self._decide(tick, state, events, now) + if cue is None: + return None + try: + await self._apply(cue) + except Exception: # never break the tick on a camera hiccup + logger.debug("Camera move failed for cue %s", cue.reason, exc_info=True) + return None + self._record(cue) + return cue + + def _decide( + self, + tick: int, + state: GameState, + events: list[RimAPIEvent], + now: float, + ) -> CameraCue | None: + # 1. Story event takes the cut. + selected = self._select_event(events) + if selected is not None: + event, _ = selected + pawn_id = self._extract_pawn_id(event.data) + if pawn_id is not None: + return CameraCue( + timestamp=now, tick=tick, target_type="pawn", + reason=event.event_type, pawn_id=pawn_id, zoom=_ZOOM_CLOSEUP, + ) + cell = self._extract_cell(event.data) + if cell is not None: + return CameraCue( + timestamp=now, tick=tick, target_type="cell", + reason=event.event_type, x=cell[0], z=cell[1], zoom=_ZOOM_CLOSEUP, + ) + + # 2. Active raid with no SSE coords — frame the colony so the approach + # is in shot. + if state.threats: + cx, cz = self._colony_center(state) + return CameraCue( + timestamp=now, tick=tick, target_type="colony", + reason="threat_active", x=cx, z=cz, zoom=_ZOOM_COLONY, + ) + + # 3. Idle: periodically pull back to the colony, otherwise zoom a pawn. + if tick % self._drift_interval == 0 or not state.colonists: + cx, cz = self._colony_center(state) + return CameraCue( + timestamp=now, tick=tick, target_type="colony", + reason="idle_drift", x=cx, z=cz, zoom=_ZOOM_COLONY, + ) + colonist = self._spotlight_colonist(state, tick) + return CameraCue( + timestamp=now, tick=tick, target_type="pawn", + reason="idle_spotlight", pawn_id=colonist.colonist_id, zoom=_ZOOM_CLOSEUP, + ) + + @staticmethod + def _colony_center(state: GameState) -> tuple[int, int]: + terrain = state.map.terrain + if terrain is not None: + return terrain.colony_center + if state.colonists: + xs = [c.position[0] for c in state.colonists] + zs = [c.position[1] for c in state.colonists] + return (sum(xs) // len(xs), sum(zs) // len(zs)) + w, h = state.map.size + return (w // 2, h // 2) + + @staticmethod + def _spotlight_colonist(state: GameState, tick: int) -> Any: + """Pick a story-worthy colonist: the most distressed (lowest mood), + else cycle through the roster so the camera doesn't fixate.""" + distressed = [c for c in state.colonists if c.mood < 0.35 or c.injuries] + if distressed: + return min(distressed, key=lambda c: c.mood) + return state.colonists[tick % len(state.colonists)] + + async def _apply(self, cue: CameraCue) -> None: + if cue.zoom is not None: + await self._client.set_camera_zoom(cue.zoom) + if cue.target_type == "pawn" and cue.pawn_id is not None: + await self._client.jump_camera_to_pawn(cue.pawn_id) + elif cue.x is not None and cue.z is not None: + await self._client.move_camera(cue.x, cue.z) + + def _record(self, cue: CameraCue) -> None: + self.cues.append(cue) + if self._cue_log_path is None: + return + try: + self._cue_log_path.parent.mkdir(parents=True, exist_ok=True) + with self._cue_log_path.open("a", encoding="utf-8") as fh: + fh.write(json.dumps(cue.model_dump()) + "\n") + except OSError: + logger.debug("Could not append camera cue to %s", self._cue_log_path) diff --git a/src/rle/orchestration/game_loop.py b/src/rle/orchestration/game_loop.py index 41e352d..3f1c523 100644 --- a/src/rle/orchestration/game_loop.py +++ b/src/rle/orchestration/game_loop.py @@ -18,6 +18,7 @@ from rle.config import RLEConfig from rle.orchestration.action_executor import ActionExecutor, ExecutionResult from rle.orchestration.action_resolver import ActionResolver +from rle.orchestration.camera_director import CameraDirector from rle.orchestration.state_manager import GameStateManager from rle.rimapi.client import RimAPIClient from rle.rimapi.schemas import GameState @@ -83,6 +84,8 @@ def __init__( cost_tracker: CostTracker | None = None, triggered_incidents: list[TriggeredIncident] | None = None, screenshots_enabled: bool = False, + auto_dismiss_dialogs: bool = True, + camera_director: CameraDirector | None = None, ) -> None: self._config = config self._client = client @@ -124,6 +127,8 @@ def __init__( self._cost_tracker = cost_tracker self._triggered_incidents = triggered_incidents or [] self._screenshots_enabled = screenshots_enabled + self._auto_dismiss_dialogs = auto_dismiss_dialogs + self._camera_director = camera_director # Hub-spoke communication — agents read messages from their spokes self._hub = CentralPost(max_agents=len(agents)) @@ -144,6 +149,26 @@ def _emit( def cost_tracker(self) -> CostTracker | None: return self._cost_tracker + async def _dismiss_blocking_dialogs(self, tick_num: int) -> None: + """Close force-pause popups that stall unattended runs (issue #33). + + The colony-name dialog (Dialog_NamePlayerSettlement) force-pauses the + game ~once per run; the dev-mode debug-log window auto-opens on RIMAPI + errors and obscures footage. Both are dismissed every tick via RIMAPI's + window/close endpoint. No-ops gracefully on older RIMAPI builds. + """ + try: + result = await self._client.close_windows(force_pause_only=True) + except Exception: + logger.debug("Dialog dismissal failed", exc_info=True) + return + closed = result.get("closed_windows") or [] + if closed: + logger.info("Dismissed force-pause window(s): %s", ", ".join(closed)) + self._emit( + EventType.TICK_START, tick_num, dismissed_windows=list(closed), + ) + def _update_visualizer_agent( self, agent: RimWorldRoleAgent, plan: ActionPlan, macro_time: float, ) -> None: @@ -306,9 +331,12 @@ async def _deliberate_agent( if usage and isinstance(usage, dict): pt = usage.get("prompt_tokens", 0) ct = usage.get("completion_tokens", 0) + rt = usage.get("reasoning_tokens", 0) + if not isinstance(rt, int): + rt = 0 if isinstance(pt, int) and isinstance(ct, int): if self._cost_tracker: - self._cost_tracker.record_raw(pt, ct) + self._cost_tracker.record_raw(pt, ct, rt) raw_output = agent._last_raw_output raw_output_truncated = ( raw_output[:_RAW_OUTPUT_CHARS] if raw_output else None @@ -320,6 +348,7 @@ async def _deliberate_agent( self._emit( EventType.PROVIDER_CALL, tick_num, agent=plan.role, prompt_tokens=pt, completion_tokens=ct, + reasoning_tokens=rt, raw_output=raw_output_truncated, raw_output_truncated=was_truncated, ) @@ -482,6 +511,11 @@ async def run_tick(self) -> TickResult: self._emit(EventType.TICK_START, tick_num) + # 1a. Dismiss force-pause nuisance windows (colony-name dialog, debug + # log) so unattended runs don't stall mid-benchmark (issue #33). + if self._auto_dismiss_dialogs: + await self._dismiss_blocking_dialogs(tick_num) + # 1b. Fire scheduled incidents (before state read captures effects) if self._triggered_incidents: await self._fire_scheduled_incidents(tick_num) @@ -494,6 +528,13 @@ async def run_tick(self) -> TickResult: day=state.colony.day, macro_time=current_time, ) + # 2b. Drive the cinematic camera to this tick's focus (opt-in capture + # runs only; never raises into the tick). Issue #34. + if self._camera_director is not None: + await self._camera_director.direct( + tick_num, state, self._state_manager.pending_events, _time.time(), + ) + # 3. Route previous tick's messages to agent spokes + broadcast phase changes messages_before = self._hub.total_messages_processed self._spoke_manager.process_all_messages() diff --git a/src/rle/rimapi/client.py b/src/rle/rimapi/client.py index 3759b8f..e53922f 100644 --- a/src/rle/rimapi/client.py +++ b/src/rle/rimapi/client.py @@ -474,6 +474,51 @@ async def take_screenshot( except (RimAPIResponseError, RimAPIConnectionError): return None + async def move_camera(self, x: int, z: int) -> Any: + """Jump the game camera to a map cell (cinematic capture, issue #34).""" + return await self._post(f"/api/v1/camera/change/position?x={int(x)}&y={int(z)}") + + async def set_camera_zoom(self, zoom: int) -> Any: + """Set the camera zoom level (smaller = closer).""" + return await self._post(f"/api/v1/camera/change/zoom?zoom={int(zoom)}") + + async def jump_camera_to_pawn(self, pawn_id: str | int) -> Any: + """Jump/follow the camera to a pawn by id (cinematic capture, issue #34).""" + return await self._post( + f"/api/v1/camera/follow/pawn?pawn_id={self._int_id(str(pawn_id))}" + ) + + async def close_windows( + self, + window_types: list[str] | None = None, + force_pause_only: bool = True, + ) -> dict[str, Any]: + """Dismiss open windows (issue #33). + + With ``window_types`` set, closes windows whose runtime type name + contains any of the given substrings (e.g. ``["Log"]`` closes + ``EditWindow_Log``). Otherwise closes every force-pause window — the + colony-name dialog and debug log that stall unattended benchmark runs. + Returns ``{"closed_count": int, "closed_windows": [...]}`` (best effort; + empty on older RIMAPI builds without the endpoint). + """ + body: dict[str, Any] = {"force_pause_only": force_pause_only} + if window_types: + body["window_types"] = window_types + try: + data = await self._post("/api/v1/ui/window/close", json=body) + except (RimAPIResponseError, RimAPIConnectionError): + return {"closed_count": 0, "closed_windows": []} + return data if isinstance(data, dict) else {"closed_count": 0, "closed_windows": []} + + async def list_windows(self) -> list[dict[str, Any]]: + """List currently open windows and whether each force-pauses the game.""" + try: + data = await self._get("/api/v1/ui/windows") + except (RimAPIResponseError, RimAPIConnectionError): + return [] + return data if isinstance(data, list) else [] + async def get_resources( self, power_info: PowerData | None = None, ) -> ResourceData: @@ -1113,7 +1158,17 @@ async def toggle_power(self, building_id: int, power_on: bool) -> Any: @staticmethod def _normalize_plant_def(plant_def: str) -> str: - """Normalize agent plant names to RimWorld defNames.""" + """Normalize agent plant names to RimWorld defNames. + + Audited for issue #33: this maps loose names ONTO the canonical defName + ("rice"/"PlantRice" → "Plant_Rice"), which is the form RimWorld's + DefDatabase actually wants — confirmed against Core defs (Plant_Rice, + Plant_Potato, ... are real; bare "rice" is not). It does NOT mangle good + names. The spread's "Invalid plant definition: Plant_Rice" failures were + NOT a def-name problem: Plant_Rice succeeded on tick 0, then every repeat + hit cells already owned by that zone (RIMAPI mislabelled the overlap). + The fix lives in the executor's overlap guard + the RIMAPI error message. + """ if plant_def.startswith("Plant_"): return plant_def # "PlantPotato" → "Plant_Potato", "potato" → "Plant_Potato" diff --git a/src/rle/tracking/cost_tracker.py b/src/rle/tracking/cost_tracker.py index 9892d76..03ae790 100644 --- a/src/rle/tracking/cost_tracker.py +++ b/src/rle/tracking/cost_tracker.py @@ -14,16 +14,31 @@ class TokenUsage(BaseModel): - """Token usage from a single LLM call.""" + """Token usage from a single LLM call. + + ``reasoning_tokens`` are the hidden chain-of-thought tokens that thinking + models (Nemotron, DeepSeek-R1, Gemini-thinking, etc.) emit. OpenRouter + reports them in ``usage.completion_tokens_details.reasoning_tokens`` and — + critically — does NOT fold them into ``completion_tokens``, yet bills them + at the completion rate. Tracking them separately is what closed the gap + between our estimates and the OpenRouter dashboard actuals (see issue #33: + deepseekv4 was undercounted +187%, gemini35 +35%). + """ model_config = ConfigDict(frozen=True) prompt_tokens: int completion_tokens: int + reasoning_tokens: int = 0 @property def total_tokens(self) -> int: - return self.prompt_tokens + self.completion_tokens + return self.prompt_tokens + self.completion_tokens + self.reasoning_tokens + + @property + def billable_completion_tokens(self) -> int: + """Output tokens billed at the completion rate (visible + reasoning).""" + return self.completion_tokens + self.reasoning_tokens class CostSnapshot(BaseModel): @@ -33,6 +48,7 @@ class CostSnapshot(BaseModel): total_prompt_tokens: int total_completion_tokens: int + total_reasoning_tokens: int total_tokens: int estimated_cost_usd: float wall_time_s: float @@ -63,6 +79,7 @@ def __init__( self._pricing_source = pricing_source self._total_prompt = 0 self._total_completion = 0 + self._total_reasoning = 0 self._num_calls = 0 self._start_time = time.monotonic() @@ -70,22 +87,40 @@ def record(self, usage: TokenUsage) -> None: """Record token usage from one LLM call.""" self._total_prompt += usage.prompt_tokens self._total_completion += usage.completion_tokens + self._total_reasoning += usage.reasoning_tokens self._num_calls += 1 - def record_raw(self, prompt_tokens: int, completion_tokens: int) -> None: + def record_raw( + self, + prompt_tokens: int, + completion_tokens: int, + reasoning_tokens: int = 0, + ) -> None: """Record from raw token counts (convenience for dict-based usage).""" - self.record(TokenUsage(prompt_tokens=prompt_tokens, completion_tokens=completion_tokens)) + self.record( + TokenUsage( + prompt_tokens=prompt_tokens, + completion_tokens=completion_tokens, + reasoning_tokens=reasoning_tokens, + ) + ) def snapshot(self) -> CostSnapshot: - """Current cumulative cost.""" - total = self._total_prompt + self._total_completion + """Current cumulative cost. + + Reasoning tokens are billed at the completion rate — providers that + emit hidden chain-of-thought (OpenRouter, OpenAI o-series) charge them + as output but report them outside ``completion_tokens``. + """ + total = self._total_prompt + self._total_completion + self._total_reasoning cost = ( self._total_prompt * self._prompt_price - + self._total_completion * self._completion_price + + (self._total_completion + self._total_reasoning) * self._completion_price ) return CostSnapshot( total_prompt_tokens=self._total_prompt, total_completion_tokens=self._total_completion, + total_reasoning_tokens=self._total_reasoning, total_tokens=total, estimated_cost_usd=round(cost, 6), wall_time_s=round(time.monotonic() - self._start_time, 2), diff --git a/src/rle/tracking/event_log.py b/src/rle/tracking/event_log.py index cb40113..79b932e 100644 --- a/src/rle/tracking/event_log.py +++ b/src/rle/tracking/event_log.py @@ -109,8 +109,11 @@ def summary(self) -> RunSummary: elif event.event_type == EventType.PROVIDER_CALL: pt = event.data.get("prompt_tokens", 0) ct = event.data.get("completion_tokens", 0) + rt = event.data.get("reasoning_tokens", 0) + if not isinstance(rt, int): + rt = 0 if isinstance(pt, int) and isinstance(ct, int): - total_tokens += pt + ct + total_tokens += pt + ct + rt cost = event.data.get("estimated_cost", 0.0) if isinstance(cost, (int, float)): total_cost += float(cost) diff --git a/tests/unit/test_action_executor.py b/tests/unit/test_action_executor.py index 6983989..d942e52 100644 --- a/tests/unit/test_action_executor.py +++ b/tests/unit/test_action_executor.py @@ -139,6 +139,50 @@ async def test_outcomes_preserve_order(self) -> None: assert [o.target_colonist_id for o in result.outcomes] == ["1", "2"] +class TestGrowingZoneIdempotency: + """Issue #33: agents re-issue the same growing zone every tick; repeats + overlap the first zone's cells and fail. The executor short-circuits + overlapping repeats with a clear error instead of doomed RIMAPI calls.""" + + def _zone(self, x1: int, z1: int, x2: int, z2: int) -> Action: + return Action( + action_type="growing_zone", + parameters={ + "map_id": 0, "plant_def": "Plant_Rice", + "x1": x1, "z1": z1, "x2": x2, "z2": z2, + }, + ) + + async def test_first_growing_zone_succeeds(self) -> None: + client = AsyncMock() + executor = ActionExecutor(client) + result = await executor.execute(_make_plan(self._zone(132, 137, 139, 144))) + assert result.executed == 1 + client.create_growing_zone.assert_awaited_once() + + async def test_overlapping_repeat_is_rejected(self) -> None: + client = AsyncMock() + executor = ActionExecutor(client) + # First creation succeeds. + await executor.execute(_make_plan(self._zone(132, 137, 139, 144))) + # Identical re-issue next tick: overlaps, must be blocked. + result = await executor.execute(_make_plan(self._zone(132, 137, 139, 144))) + assert result.failed == 1 + assert result.executed == 0 + assert result.outcomes[0].error is not None + assert "already" in result.outcomes[0].error.lower() + # Only the first call reached RIMAPI. + client.create_growing_zone.assert_awaited_once() + + async def test_non_overlapping_zone_allowed(self) -> None: + client = AsyncMock() + executor = ActionExecutor(client) + await executor.execute(_make_plan(self._zone(132, 137, 139, 144))) + result = await executor.execute(_make_plan(self._zone(150, 150, 157, 157))) + assert result.executed == 1 + assert client.create_growing_zone.await_count == 2 + + class TestDispatch: async def test_set_work_priority(self) -> None: client = AsyncMock() diff --git a/tests/unit/test_base_role.py b/tests/unit/test_base_role.py index 6a43b8d..fff9582 100644 --- a/tests/unit/test_base_role.py +++ b/tests/unit/test_base_role.py @@ -3,6 +3,7 @@ from __future__ import annotations import json +from types import SimpleNamespace from typing import Any, ClassVar from unittest.mock import MagicMock @@ -454,3 +455,51 @@ async def test_acall_applies_no_think_prefill( messages = mock_provider.acomplete.call_args[0][0] assert messages[-1].role == MessageRole.ASSISTANT assert messages[-1].content == "" + + +# ------------------------------------------------------------------ +# reasoning-token extraction (issue #33: thinking-model cost undercount) +# ------------------------------------------------------------------ + + +class TestReasoningTokenExtraction: + def test_none_raw_response(self) -> None: + assert RimWorldRoleAgent._extract_reasoning_tokens(None) == 0 + + def test_openai_object_shape(self) -> None: + details = SimpleNamespace(reasoning_tokens=4096) + usage = SimpleNamespace(completion_tokens_details=details) + raw = SimpleNamespace(usage=usage) + assert RimWorldRoleAgent._extract_reasoning_tokens(raw) == 4096 + + def test_openrouter_dict_shape(self) -> None: + raw = {"usage": {"completion_tokens_details": {"reasoning_tokens": 1234}}} + assert RimWorldRoleAgent._extract_reasoning_tokens(raw) == 1234 + + def test_reasoning_directly_on_usage(self) -> None: + raw = {"usage": {"reasoning_tokens": 77}} + assert RimWorldRoleAgent._extract_reasoning_tokens(raw) == 77 + + def test_absent_reasoning_returns_zero(self) -> None: + raw = {"usage": {"prompt_tokens": 10, "completion_tokens": 5}} + assert RimWorldRoleAgent._extract_reasoning_tokens(raw) == 0 + + def test_unparseable_returns_zero(self) -> None: + raw = {"usage": {"completion_tokens_details": {"reasoning_tokens": "lots"}}} + assert RimWorldRoleAgent._extract_reasoning_tokens(raw) == 0 + + def test_record_completion_merges_reasoning_into_usage( + self, mock_provider: MagicMock, helix: HelixGeometry, + ) -> None: + agent = _DummyRoleAgent("d-01", mock_provider, helix, spawn_time=0.0) + result = CompletionResult( + content="{}", + model="mock", + usage={"prompt_tokens": 100, "completion_tokens": 50, "total_tokens": 150}, + raw_response={"usage": {"completion_tokens_details": {"reasoning_tokens": 900}}}, + ) + agent._record_completion(result) + assert agent._last_usage is not None + assert agent._last_usage["reasoning_tokens"] == 900 + # original usage dict on the result is not mutated + assert "reasoning_tokens" not in result.usage diff --git a/tests/unit/test_camera_director.py b/tests/unit/test_camera_director.py new file mode 100644 index 0000000..d0ae2b7 --- /dev/null +++ b/tests/unit/test_camera_director.py @@ -0,0 +1,134 @@ +"""Tests for the cinematic CameraDirector (issue #34).""" + +from __future__ import annotations + +import json +from pathlib import Path +from unittest.mock import AsyncMock + +from rle.orchestration.camera_director import CameraDirector +from rle.rimapi.schemas import ColonistData, GameState +from rle.rimapi.sse_client import RimAPIEvent + + +def _event(event_type: str, **data: object) -> RimAPIEvent: + return RimAPIEvent(event_type, dict(data), 1700000000.0) + + +def _colonist( + cid: str, mood: float, pos: tuple[int, int], injuries: list[str] | None = None, +) -> ColonistData: + return ColonistData( + colonist_id=cid, name=cid, health=1.0, mood=mood, skills={}, + traits=[], current_job=None, is_drafted=False, needs={}, + injuries=injuries or [], position=pos, + ) + + +def _state(sample_game_state: GameState, **overrides: object) -> GameState: + return sample_game_state.model_copy(update=overrides) + + +class TestTargetExtraction: + def test_extract_pawn_id_variants(self) -> None: + assert CameraDirector._extract_pawn_id({"pawn_id": 184}) == "184" + assert CameraDirector._extract_pawn_id({"colonist_id": "col_2"}) == "col_2" + assert CameraDirector._extract_pawn_id({"pawn_id": 0}) is None + assert CameraDirector._extract_pawn_id({}) is None + + def test_extract_cell_variants(self) -> None: + assert CameraDirector._extract_cell({"position": {"x": 10, "z": 20}}) == (10, 20) + assert CameraDirector._extract_cell({"position": {"x": 10, "y": 20}}) == (10, 20) + assert CameraDirector._extract_cell({"position": [5, 6]}) == (5, 6) + assert CameraDirector._extract_cell({"x": 7, "z": 8}) == (7, 8) + assert CameraDirector._extract_cell({"foo": "bar"}) is None + + +class TestDecisions: + async def test_event_with_pawn_id_jumps_to_pawn(self, sample_game_state: GameState) -> None: + client = AsyncMock() + director = CameraDirector(client) + cue = await director.direct( + 1, sample_game_state, [_event("pawn_downed", pawn_id=184)], 1.0, + ) + assert cue is not None + assert cue.target_type == "pawn" + assert cue.pawn_id == "184" + assert cue.reason == "pawn_downed" + client.jump_camera_to_pawn.assert_awaited_once_with("184") + + async def test_event_with_cell_moves_camera(self, sample_game_state: GameState) -> None: + client = AsyncMock() + director = CameraDirector(client) + cue = await director.direct( + 1, sample_game_state, [_event("pawn_killed", position={"x": 30, "z": 40})], 1.0, + ) + assert cue is not None + assert cue.target_type == "cell" + assert (cue.x, cue.z) == (30, 40) + client.move_camera.assert_awaited_once_with(30, 40) + + async def test_highest_priority_event_wins(self, sample_game_state: GameState) -> None: + client = AsyncMock() + director = CameraDirector(client) + events = [ + _event("colonist_mental_break", pawn_id=5), + _event("pawn_killed", pawn_id=9), + ] + cue = await director.direct(1, sample_game_state, events, 1.0) + assert cue is not None + assert cue.reason == "pawn_killed" + assert cue.pawn_id == "9" + + async def test_threat_with_no_event_frames_colony(self, sample_game_state: GameState) -> None: + # sample_game_state already carries a threat. + client = AsyncMock() + director = CameraDirector(client) + cue = await director.direct(1, sample_game_state, [], 1.0) + assert cue is not None + assert cue.target_type == "colony" + assert cue.reason == "threat_active" + client.move_camera.assert_awaited_once() + + async def test_idle_drift_on_interval(self, sample_game_state: GameState) -> None: + client = AsyncMock() + director = CameraDirector(client, drift_interval=4) + state = _state(sample_game_state, threats=[]) + cue = await director.direct(4, state, [], 1.0) # tick % 4 == 0 + assert cue is not None + assert cue.reason == "idle_drift" + assert cue.target_type == "colony" + + async def test_idle_spotlights_most_distressed(self, sample_game_state: GameState) -> None: + client = AsyncMock() + director = CameraDirector(client, drift_interval=4) + roster = [ + _colonist("happy", 0.9, (10, 10)), + _colonist("sad", 0.1, (20, 20)), + ] + state = _state(sample_game_state, threats=[], colonists=roster) + cue = await director.direct(1, state, [], 1.0) # tick % 4 != 0 + assert cue is not None + assert cue.reason == "idle_spotlight" + assert cue.pawn_id == "sad" + + +class TestCueLog: + async def test_cue_log_written(self, sample_game_state: GameState, tmp_path: Path) -> None: + client = AsyncMock() + director = CameraDirector(client, output_dir=tmp_path) + await director.direct(1, sample_game_state, [_event("pawn_killed", pawn_id=3)], 99.5) + log = tmp_path / "camera_cues.jsonl" + assert log.exists() + record = json.loads(log.read_text(encoding="utf-8").strip()) + assert record["pawn_id"] == "3" + assert record["timestamp"] == 99.5 + assert len(director.cues) == 1 + + async def test_camera_failure_is_swallowed(self, sample_game_state: GameState) -> None: + client = AsyncMock() + client.jump_camera_to_pawn.side_effect = RuntimeError("no endpoint") + director = CameraDirector(client) + cue = await director.direct(1, sample_game_state, [_event("pawn_downed", pawn_id=3)], 1.0) + assert cue is None + assert director.cues == [] diff --git a/tests/unit/test_cost_tracker.py b/tests/unit/test_cost_tracker.py index 2b29e30..349576a 100644 --- a/tests/unit/test_cost_tracker.py +++ b/tests/unit/test_cost_tracker.py @@ -64,6 +64,16 @@ def test_total_tokens(self) -> None: usage = TokenUsage(prompt_tokens=100, completion_tokens=50) assert usage.total_tokens == 150 + def test_total_tokens_includes_reasoning(self) -> None: + usage = TokenUsage(prompt_tokens=100, completion_tokens=50, reasoning_tokens=200) + assert usage.total_tokens == 350 + assert usage.billable_completion_tokens == 250 + + def test_reasoning_defaults_to_zero(self) -> None: + usage = TokenUsage(prompt_tokens=100, completion_tokens=50) + assert usage.reasoning_tokens == 0 + assert usage.billable_completion_tokens == 50 + def test_frozen(self) -> None: usage = TokenUsage(prompt_tokens=10, completion_tokens=5) with pytest.raises(Exception): @@ -97,6 +107,16 @@ def test_record_raw_works_as_convenience(self) -> None: assert snap.total_completion_tokens == 100 assert snap.num_calls == 2 + def test_record_accumulates_reasoning_tokens(self) -> None: + tracker = CostTracker("test-model") + tracker.record(TokenUsage(prompt_tokens=100, completion_tokens=50, reasoning_tokens=300)) + tracker.record_raw(prompt_tokens=100, completion_tokens=50, reasoning_tokens=200) + + snap = tracker.snapshot() + assert snap.total_reasoning_tokens == 500 + # total_tokens folds reasoning in: (100+50) + (100+50) + 500 + assert snap.total_tokens == 800 + def test_record_and_record_raw_combined(self) -> None: tracker = CostTracker("test-model") tracker.record(TokenUsage(prompt_tokens=50, completion_tokens=25)) @@ -126,6 +146,21 @@ def test_snapshot_computes_cost_correctly(self) -> None: # 1000 * 0.000005 + 500 * 0.000025 = 0.005 + 0.0125 = 0.0175 assert snap.estimated_cost_usd == pytest.approx(0.0175, rel=1e-5) + def test_reasoning_tokens_billed_at_completion_rate(self) -> None: + tracker = CostTracker( + "thinking-model", + prompt_price=0.000005, + completion_price=0.000025, + ) + tracker.record( + TokenUsage(prompt_tokens=1000, completion_tokens=500, reasoning_tokens=4000) + ) + + snap = tracker.snapshot() + # prompt: 1000 * 5e-6 = 0.005 + # completion + reasoning: (500 + 4000) * 25e-6 = 0.1125 + assert snap.estimated_cost_usd == pytest.approx(0.1175, rel=1e-5) + def test_snapshot_zero_cost_with_default_prices(self) -> None: tracker = CostTracker("free-model") tracker.record(TokenUsage(prompt_tokens=10000, completion_tokens=5000))