Agent-bilevel: horizon-faithful plan capture + explorer fixes (solves plain domino 5/5 across 5 seeds)

predicators/agent_sdk/agent_session_mixin.py

@@ -2,7 +2,7 @@
 
 Extracts common code for ToolContext initialization, lazy
 AgentSessionManager creation, async-to-sync bridging, and agent explorer
-creation from AgentPlannerApproach and AgentAbstractionLearningApproach.
+creation shared by AgentPlannerApproach and its subclasses.
 """
 import asyncio
 import logging

predicators/agent_sdk/docker_agent_runner.py

@@ -72,13 +72,27 @@ async def _run_query(query_input: Dict[str, Any]) -> Dict[str, Any]:
     mcp_tool_list = get_allowed_tool_list(tool_names)
     allowed_tools = BUILTIN_TOOLS + mcp_tool_list
 
+    # Cap per-response extended thinking so deliberation can't blow the
+    # harness output-token limit (the 32000-token overflow). Fed via
+    # query_input (this runner has no CFG); default mirrors settings.
+    thinking_budget = query_input.get("thinking_budget_tokens", 16000)
+    thinking = ({
+        "type": "enabled",
+        "budget_tokens": thinking_budget
+    } if thinking_budget and thinking_budget > 0 else None)
+    # Reasoning effort: one of the SDK levels, or unset for ""/"default".
+    effort = str(query_input.get("reasoning_effort", "")).strip().lower()
+    reasoning_effort = (effort if effort in {"low", "medium", "high", "max"}
+                        else None)
     options = ClaudeAgentOptions(
         allowed_tools=allowed_tools,
         mcp_servers={"predicator_tools": mcp_server},
         permission_mode="bypassPermissions",
         system_prompt=query_input["system_prompt"],
         model=query_input["model_name"],
         max_turns=query_input.get("max_turns", 20),
+        thinking=thinking,  # type: ignore[arg-type]
+        effort=reasoning_effort,  # type: ignore[arg-type]
     )
 
     client = ClaudeSDKClient(options=options)
@@ -129,9 +143,9 @@ def _flush_log() -> None:
                             file=sys.stderr,
                             flush=True)
                     elif btype == "ThinkingBlock":
-                        thinking = block.get("thinking", "")
-                        if thinking:
-                            print(f"Thinking: {thinking[:200]}...",
+                        thinking_text = str(block.get("thinking", ""))
+                        if thinking_text:
+                            print(f"Thinking: {thinking_text[:200]}...",
                                   file=sys.stderr,
                                   flush=True)
             elif entry["type"] == "result":

predicators/agent_sdk/docker_sandbox.py

@@ -47,7 +47,7 @@
 
 from predicators.agent_sdk.sandbox_prompts import build_claude_md, \
     build_sandbox_system_prompt, find_repo_root, setup_sandbox_directory
-from predicators.agent_sdk.tools import ToolContext
+from predicators.agent_sdk.tools import ToolContext, session_log_filename
 from predicators.settings import CFG
 
 logger = logging.getLogger(__name__)
@@ -234,7 +234,9 @@ async def query(self,
         # Counter-first layout: alphabetical sort matches chronological
         # order across mixed ``learn``/``test``/``explore`` phases.
         timestamp = datetime.datetime.now().strftime("%Y%m%d_%H%M%S")
-        log_filename = f"{self._query_count:03d}_{kind}_{timestamp}.md"
+        log_filename = session_log_filename(
+            self._query_count, kind, timestamp,
+            getattr(self._tool_context, "test_task_idx", None))
         if self._log_dir:
             os.makedirs(self._log_dir, exist_ok=True)
             incremental_log_path = os.path.join(self._log_dir, log_filename)
@@ -253,6 +255,8 @@ async def query(self,
                 "system_prompt": self._system_prompt,
                 "model_name": self._model_name,
                 "max_turns": CFG.agent_sdk_max_agent_turns_per_iteration,
+                "thinking_budget_tokens": CFG.agent_sdk_thinking_budget_tokens,
+                "reasoning_effort": CFG.agent_sdk_reasoning_effort,
                 "tool_names": self._tool_names,
                 "cfg_snapshot": dict(CFG.__dict__),
                 "log_path": container_log_path,
@@ -540,7 +544,9 @@ def _save_query_response_log(self, query: str,
 
         timestamp = datetime.datetime.now().strftime("%Y%m%d_%H%M%S")
         kind = getattr(self, "_last_kind", "query")
-        filename = f"{self._query_count:03d}_{kind}_{timestamp}.md"
+        filename = session_log_filename(
+            self._query_count, kind, timestamp,
+            getattr(self._tool_context, "test_task_idx", None))
         filepath = os.path.join(self._log_dir, filename)
 
         lines = [

predicators/agent_sdk/local_sandbox.py

@@ -33,7 +33,8 @@
 from predicators.agent_sdk.sandbox_prompts import build_claude_md, \
     build_sandbox_system_prompt, find_repo_root, setup_sandbox_directory, \
     truncate
-from predicators.agent_sdk.tools import BUILTIN_TOOLS, ToolContext
+from predicators.agent_sdk.tools import BUILTIN_TOOLS, ToolContext, \
+    session_log_filename
 from predicators.settings import CFG
 
 logger = logging.getLogger(__name__)
@@ -75,6 +76,10 @@ def __init__(
         self._phase = phase
 
         self._total_cost_usd: float = 0.0
+        # The SDK reports total_cost_usd as the cumulative cost of the
+        # reused session, so we track the last value seen to derive the
+        # per-solve (marginal) cost of each query.
+        self._last_cost_usd: float = 0.0
         self._total_turns: int = 0
         self._query_count: int = 0
         self._session_id: Optional[str] = None
@@ -178,13 +183,31 @@ async def start_session(self) -> None:
         allowed_tools = BUILTIN_TOOLS + mcp_tool_list
 
         extra_hooks = dict(self._tool_context.extra_session_hooks or {})
+        # Cap per-response extended thinking so deliberation can't blow the
+        # harness output-token limit (the 32000-token overflow). Keeps the
+        # model's effort otherwise at its default (high).
+        thinking = ({
+            "type": "enabled",
+            "budget_tokens": CFG.agent_sdk_thinking_budget_tokens
+        } if CFG.agent_sdk_thinking_budget_tokens > 0 else None)
+        # Reasoning effort: pass through to the agent when set to one of the
+        # SDK's accepted levels; "" / "default" leaves it unset.
+        effort = CFG.agent_sdk_reasoning_effort.strip().lower()
+        valid_efforts = {"low", "medium", "high", "max"}
+        if effort and effort not in valid_efforts and effort != "default":
+            raise ValueError(f"agent_sdk_reasoning_effort must be one of "
+                             f"{sorted(valid_efforts)} or ''/'default'; got "
+                             f"{CFG.agent_sdk_reasoning_effort!r}")
+        reasoning_effort = effort if effort in valid_efforts else None
         options = ClaudeAgentOptions(
             allowed_tools=allowed_tools,
             mcp_servers={"predicator_tools": mcp_server},
             permission_mode="bypassPermissions",
             system_prompt=self._system_prompt,
             model=self._model_name,
             max_turns=CFG.agent_sdk_max_agent_turns_per_iteration,
+            thinking=thinking,  # type: ignore[arg-type]
+            effort=reasoning_effort,  # type: ignore[arg-type]
             cwd=self._sandbox_dir,
             setting_sources=["project", "local"],
             hooks=(extra_hooks
@@ -246,13 +269,29 @@ async def query(self,
                 elif entry["type"] == "result":
                     cost = entry.get("total_cost_usd")
                     turns = entry.get("num_turns")
+                    solve_cost: Optional[float] = None
                     if cost is not None:
-                        self._total_cost_usd += cost
+                        # cost is the session's cumulative total; the
+                        # per-solve cost is the delta since the last result.
+                        # A drop below the last value means the session was
+                        # reset (e.g. recovery), so the new cumulative is
+                        # itself the delta.
+                        solve_cost = float(cost -
+                                           self._last_cost_usd if cost >= self.
+                                           _last_cost_usd else cost)
+                        self._last_cost_usd = cost
+                        self._total_cost_usd += solve_cost
+                        self._current_log_meta["solve_cost_usd"] = solve_cost
+                        self._current_log_meta["total_cost_usd"] = \
+                            self._total_cost_usd
                     if turns is not None:
                         self._total_turns += turns
                     logging.info(
-                        "Local sandbox iteration complete. "
-                        "Turns: %s, Cost: $%s", turns or '?', cost or '?')
+                        "Local sandbox iteration complete. Turns: %s, "
+                        "Cost this solve: $%s, Total cost so far: $%s", turns
+                        or '?',
+                        f"{solve_cost:.4f}" if solve_cost is not None else '?',
+                        f"{self._total_cost_usd:.4f}")
 
                 # Flush log after each message
                 if log_path:
@@ -333,11 +372,13 @@ def save_session_info(self) -> None:
 
     # -- Logging helpers --
 
-    # Matches both the new ``NNN_kind_ts.md`` layout and the legacy
+    # Matches the new ``NNN_kind[_taskN]_ts.md`` layout and the legacy
     # ``kind_NNN_ts.md`` layout so resuming across the migration is
-    # lossless. The counter is always captured in group 1 or 2.
+    # lossless. The counter is always captured in group 1 or 2; the
+    # optional ``_task<idx>`` segment tags test queries with their task.
     _LOG_FILENAME_RE = re.compile(
-        r"^(?:(\d{3})_[a-z][a-z_]*|[a-z][a-z_]*_(\d{3}))_\d{8}_\d{6}\.md$")
+        r"^(?:(\d{3})_[a-z][a-z_]*(?:_task\d+)?|[a-z][a-z_]*_(\d{3}))"
+        r"_\d{8}_\d{6}\.md$")
 
     def _seed_query_count_from_log_dir(self) -> None:
         """Make the per-session counter continuous across the run.
@@ -375,8 +416,11 @@ def _init_incremental_log(self,
 
         timestamp = datetime.datetime.now().strftime("%Y%m%d_%H%M%S")
         # Counter-first layout: alphabetical sort matches chronological
-        # order across mixed ``learn``/``test``/``explore`` phases.
-        filename = f"{self._query_count:03d}_{kind}_{timestamp}.md"
+        # order across mixed ``learn``/``test``/``explore`` phases. Test
+        # queries also carry a ``_task<idx>`` segment for attribution.
+        filename = session_log_filename(
+            self._query_count, kind, timestamp,
+            getattr(self._tool_context, "test_task_idx", None))
         # Primary: main log dir (host-visible)
         filepath = os.path.join(self._log_dir, filename)
         os.makedirs(self._log_dir, exist_ok=True)

predicators/agent_sdk/log_formatter.py

@@ -59,8 +59,17 @@ def format_conversation_markdown(
 
         elif etype == "result":
             turns = entry.get("num_turns", "?")
-            cost = entry.get("total_cost_usd")
-            cost_str = f"${cost:.2f}" if cost is not None else "?"
+            # Prefer the per-solve/total split the sandbox derives (the
+            # raw total_cost_usd is the cumulative session cost); fall
+            # back to the raw cumulative value when it isn't supplied.
+            solve_cost = meta.get("solve_cost_usd") if meta else None
+            total_cost = meta.get("total_cost_usd") if meta else None
+            if solve_cost is not None and total_cost is not None:
+                cost_str = (f"${solve_cost:.2f} this solve, "
+                            f"${total_cost:.2f} total")
+            else:
+                cost = entry.get("total_cost_usd")
+                cost_str = f"${cost:.2f}" if cost is not None else "?"
             lines.append(f"---\n\n**Result:** {turns} turns, {cost_str}\n")
 
         elif etype == "error":

predicators/agent_sdk/proposal_parser.py

@@ -21,7 +21,7 @@ class ProposalBundle:
     # Retractions: names of previously-proposed abstractions to remove
     retract_type_names: Set[str] = field(default_factory=set)
     retract_predicate_names: Set[str] = field(default_factory=set)
-    retract_object_augmentor: bool = False
+    retract_task_augmentor: bool = False
     retract_process_names: Set[str] = field(default_factory=set)
     retract_option_names: Set[str] = field(default_factory=set)
 

predicators/agent_sdk/sandbox_prompts.py

@@ -174,7 +174,7 @@ def deny(reason):
     Read ./session_logs/001_learn_*.md
 
 ## Scene Images
-`test_option_plan` automatically saves scene images to ./test_images/
+`evaluate_option_plan` automatically saves scene images to ./test_images/
 after each step. You can Read them to inspect the spatial state of
 the environment.
 
@@ -207,7 +207,7 @@ def deny(reason):
 - **Use visualize_state liberally** — it's free (no physics, no failure
   modes). When stuck on a step, STOP testing and visualize the object at
   several candidate positions and orientations to find the right region
-  before spending more test_option_plan calls.
+  before spending more evaluate_option_plan calls.
 - **Vary all parameters** — orientation and other non-position params
   affect both the outcome and whether the action succeeds.
 - **Search coarse-to-fine** — spread initial attempts across the full
@@ -332,7 +332,7 @@ def build_sandbox_system_prompt(
 ```
 
 ### Scene Images
-`test_option_plan` automatically saves scene images to ./test_images/
+`evaluate_option_plan` automatically saves scene images to ./test_images/
 after each plan step for later review.
 
 ### Proposed Code

predicators/agent_sdk/session_manager.py

@@ -4,6 +4,7 @@
 import json
 import logging
 import os
+import time
 from typing import Any, Dict, List, Optional
 
 from predicators.agent_sdk.response_parser import parse_message
@@ -33,6 +34,9 @@ def __init__(self,
         self._client: Any = None
         self._session_id: Optional[str] = None
         self._total_cost_usd: float = 0.0
+        # total_cost_usd from the SDK is the cumulative session cost; track
+        # the last value to derive each query's per-solve (marginal) cost.
+        self._last_cost_usd: float = 0.0
         self._total_turns: int = 0
         self._started = False
         self._query_count: int = 0
@@ -68,13 +72,20 @@ async def start_session(self) -> None:
         if self._tool_context is not None:
             extra_hooks = dict(
                 getattr(self._tool_context, "extra_session_hooks", {}) or {})
+        # Cap per-response extended thinking so deliberation can't blow the
+        # harness output-token limit (the 32000-token overflow).
+        thinking = ({
+            "type": "enabled",
+            "budget_tokens": CFG.agent_sdk_thinking_budget_tokens
+        } if CFG.agent_sdk_thinking_budget_tokens > 0 else None)
         options = ClaudeAgentOptions(
             allowed_tools=self._allowed_tools or [],
             mcp_servers={"predicator_tools": self._mcp_server},
             permission_mode="bypassPermissions",
             system_prompt=self._system_prompt,
             model=self._model_name,
             max_turns=CFG.agent_sdk_max_agent_turns_per_iteration,
+            thinking=thinking,  # type: ignore[arg-type]
             hooks=(extra_hooks
                    if extra_hooks else None),  # type: ignore[arg-type]
         )
@@ -132,6 +143,11 @@ async def query(self,
 
         collected: List[Dict[str, Any]] = []
         log_path = self._init_incremental_log(message, kind=kind)
+        start = time.perf_counter()
+        # Wall-clock of the previous response message, so each logged step
+        # can report how long it took (model thinking before a tool call,
+        # tool execution before the next message, etc.).
+        prev_t = start
 
         try:
             await self._client.query(message)
@@ -140,29 +156,50 @@ async def query(self,
                 if entry is None:
                     continue
                 collected.append(entry)
+                now = time.perf_counter()
+                dt = now - prev_t
+                prev_t = now
 
                 # Log side-effects
                 if entry["type"] == "assistant":
                     for block in entry.get("content", []):
                         if block.get("type") == "text":
-                            logging.debug("Agent: %s...", block["text"][:200])
+                            logging.debug("[+%.2fs] Agent: %s...", dt,
+                                          block["text"][:200])
+                        elif block.get("thinking") is not None:
+                            logging.debug("[+%.2fs] Agent [thinking]: %s...",
+                                          dt, block["thinking"][:200])
                         elif block.get("type") == "tool_use":
                             params = block.get("input") or {}
                             param_summary = ", ".join(
                                 f"{k}={truncate(v)}"
                                 for k, v in params.items())
-                            logging.debug("Agent tool call: %s(%s)",
-                                          block["name"], param_summary)
+                            logging.debug("[+%.2fs] Agent tool call: %s(%s)",
+                                          dt, block["name"], param_summary)
                 elif entry["type"] == "result":
                     cost = entry.get("total_cost_usd")
                     turns = entry.get("num_turns")
+                    solve_cost: Optional[float] = None
                     if cost is not None:
-                        self._total_cost_usd += cost
+                        # cost is cumulative; the per-solve cost is the
+                        # delta since the last result (a drop means the
+                        # session reset, so the new total is the delta).
+                        solve_cost = float(cost -
+                                           self._last_cost_usd if cost >= self.
+                                           _last_cost_usd else cost)
+                        self._last_cost_usd = cost
+                        self._total_cost_usd += solve_cost
+                        self._current_log_meta["solve_cost_usd"] = solve_cost
+                        self._current_log_meta["total_cost_usd"] = \
+                            self._total_cost_usd
                     if turns is not None:
                         self._total_turns += turns
                     logging.info(
-                        "Agent iteration complete. Turns: %s, Cost: $%s", turns
-                        or '?', cost or '?')
+                        "Agent iteration complete. Turns: %s, "
+                        "Cost this solve: $%s, Total cost so far: $%s", turns
+                        or '?',
+                        f"{solve_cost:.4f}" if solve_cost is not None else '?',
+                        f"{self._total_cost_usd:.4f}")
 
                 # Flush log after each message
                 if log_path:
@@ -173,6 +210,10 @@ async def query(self,
             collected.append({"type": "error", "error": str(e)})
             await self._recover_session(message)
 
+        elapsed = time.perf_counter() - start
+        logging.info("[agent-interaction] kind=%s took %.2fs (%d messages)",
+                     kind, elapsed, len(collected))
+
         # Final flush to ensure everything is saved
         if log_path:
             self._flush_log(log_path, collected)