feat: add comprehensive logging to agent sandbox (#26)

* feat: add comprehensive logging to agent sandbox

- Log each step of sandbox creation
- Check environment (which claude, PATH, API key)
- Add --output-format stream-json --verbose to claude command
- Log each line received from stdout
- Log when stream_reader starts/finishes

* feat: add logfire logging from inside Modal sandbox

Author: nikhilwoodruff

src/policyengine_api/agent_sandbox.py

@@ -42,6 +42,16 @@ def run_claude_code_in_sandbox(
 
     Returns the sandbox and process handle for streaming output.
     """
+    import logfire
+
+    from policyengine_api.config import settings
+
+    logfire.info(
+        "run_claude_code_in_sandbox: starting",
+        question=question[:100],
+        api_base_url=api_base_url,
+    )
+
     # MCP config for Claude Code (type: sse for HTTP SSE transport)
     mcp_config = f"""{{
   "mcpServers": {{
@@ -53,31 +63,91 @@ def run_claude_code_in_sandbox(
 }}"""
 
     # Get reference to deployed app (required when calling from outside Modal)
+    logfire.info("run_claude_code_in_sandbox: looking up Modal app")
     sandbox_app = modal.App.lookup("policyengine-sandbox", create_if_missing=True)
+    logfire.info("run_claude_code_in_sandbox: Modal app found")
 
+    logfire.info("run_claude_code_in_sandbox: creating sandbox")
     sb = modal.Sandbox.create(
         app=sandbox_app,
         image=sandbox_image,
         secrets=[anthropic_secret, logfire_secret],
         timeout=600,
         workdir="/tmp",
     )
+    logfire.info("run_claude_code_in_sandbox: sandbox created")
+
+    # Log from inside the sandbox via Python
+    logfire.info("run_claude_code_in_sandbox: logging from inside sandbox")
+    escaped_question = question[:50].replace("'", "\\'").replace('"', '\\"')
+    sandbox_log = sb.exec(
+        "python",
+        "-c",
+        f"""
+import logfire
+logfire.configure(token='{settings.logfire_token}', service_name='modal-sandbox-inner')
+logfire.info('Inside Modal sandbox', question='{escaped_question}')
+print('Logfire configured inside sandbox')
+""",
+    )
+    sandbox_log.wait()
+    logfire.info(
+        "run_claude_code_in_sandbox: sandbox inner log result",
+        stdout=sandbox_log.stdout.read()[:200],
+        stderr=sandbox_log.stderr.read()[:200],
+        returncode=sandbox_log.returncode,
+    )
+
+    # Check environment inside sandbox
+    logfire.info("run_claude_code_in_sandbox: checking sandbox environment")
+    env_check = sb.exec(
+        "sh",
+        "-c",
+        "which claude && echo PATH=$PATH && echo ANTHROPIC_API_KEY=${ANTHROPIC_API_KEY:0:10}...",
+    )
+    env_check.wait()
+    env_stdout = env_check.stdout.read()
+    env_stderr = env_check.stderr.read()
+    logfire.info(
+        "run_claude_code_in_sandbox: env check",
+        stdout=env_stdout[:500] if env_stdout else None,
+        stderr=env_stderr[:500] if env_stderr else None,
+        returncode=env_check.returncode,
+    )
 
     # Write MCP config
+    logfire.info("run_claude_code_in_sandbox: writing MCP config")
     sb.exec("mkdir", "-p", "/root/.claude")
     config_process = sb.exec(
         "sh", "-c", f"cat > /root/.claude/mcp_servers.json << 'EOF'\n{mcp_config}\nEOF"
     )
     config_process.wait()
+    logfire.info(
+        "run_claude_code_in_sandbox: MCP config written",
+        returncode=config_process.returncode,
+    )
+
+    # Verify config was written
+    verify_process = sb.exec("cat", "/root/.claude/mcp_servers.json")
+    verify_process.wait()
+    logfire.info(
+        "run_claude_code_in_sandbox: MCP config contents",
+        config=verify_process.stdout.read()[:500],
+    )
 
     # Run Claude Code with the question
+    logfire.info("run_claude_code_in_sandbox: starting claude CLI")
     process = sb.exec(
         "claude",
         "-p",
         question,
+        "--output-format",
+        "stream-json",
+        "--verbose",
         "--allowedTools",
         "mcp__policyengine__*,Bash,Read,Grep,Glob,Write,Edit",
     )
+    logfire.info("run_claude_code_in_sandbox: claude CLI process started, returning")
 
     return sb, process
 

src/policyengine_api/api/agent.py

@@ -114,19 +114,39 @@ async def _stream_modal_sandbox(question: str, api_base_url: str):
 
         def stream_reader():
             try:
+                logfire.info("stream_reader: starting to read stdout")
+                line_count = 0
                 for line in process.stdout:
+                    line_count += 1
+                    logfire.info(
+                        "stream_reader: got line",
+                        line_num=line_count,
+                        line_preview=line[:200] if line else None,
+                    )
                     line_queue.put(("line", line))
+                logfire.info("stream_reader: stdout exhausted, waiting for process")
                 process.wait()
+                logfire.info(
+                    "stream_reader: process finished", returncode=process.returncode
+                )
                 if process.returncode != 0:
                     stderr = process.stderr.read()
+                    logfire.error(
+                        "stream_reader: process failed",
+                        returncode=process.returncode,
+                        stderr=stderr[:500] if stderr else None,
+                    )
                     line_queue.put(("error", (process.returncode, stderr)))
                 else:
                     line_queue.put(("done", process.returncode))
             except Exception as e:
+                logfire.exception("stream_reader: exception", error=str(e))
                 line_queue.put(("exception", str(e)))
 
+        logfire.info("_stream_modal_sandbox: starting reader thread")
         reader_thread = threading.Thread(target=stream_reader, daemon=True)
         reader_thread.start()
+        logfire.info("_stream_modal_sandbox: reader thread started, entering main loop")
 
         while True:
             try:

src/policyengine_api/api/analysis.py

@@ -48,6 +48,7 @@ def _safe_float(value: float | None) -> float | None:
         return None
     return value
 
+
 # Namespace for deterministic UUIDs
 SIMULATION_NAMESPACE = UUID("a1b2c3d4-e5f6-7890-abcd-ef1234567890")
 REPORT_NAMESPACE = UUID("b2c3d4e5-f6a7-8901-bcde-f12345678901")