feat: add comprehensive DEBUG logging to Claude SDK invocation points
Add detailed debug logging throughout the spec creation and QA validation pipeline to help diagnose issues during autonomous builds. Files updated: - agents/session.py: Log session start, SDK queries, message types, tool calls (with inputs), tool results (success/error/blocked), and session completion status - spec/pipeline/agent_runner.py: Log agent run lifecycle, prompt loading, message processing, and tool execution - qa/loop.py: Log iteration progress, reviewer/fixer session status, QA verdicts, recurring issues detection, and final summary - qa/reviewer.py: Log QA reviewer session lifecycle and verdicts - qa/fixer.py: Log QA fixer session lifecycle and fix status - runners/spec_runner.py: Log orchestrator creation, run status, build approval, and command execution Usage: Set DEBUG=true and optionally DEBUG_LEVEL=1|2|3 for verbosity: DEBUG=true DEBUG_LEVEL=2 python auto-claude/run.py --spec 001 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
This commit is contained in:
AndyMik90
@@ -10,6 +10,7 @@ import logging
|
||||
from pathlib import Path
|
||||
|
||||
from claude_agent_sdk import ClaudeSDKClient
|
||||
from debug import debug, debug_detailed, debug_error, debug_section, debug_success
|
||||
from insight_extractor import extract_session_insights
|
||||
from linear_updater import (
|
||||
linear_subtask_completed,
|
||||
@@ -332,20 +333,40 @@ async def run_agent_session(
|
||||
- "complete" if all subtasks complete
|
||||
- "error" if an error occurred
|
||||
"""
|
||||
debug_section("session", f"Agent Session - {phase.value}")
|
||||
debug(
|
||||
"session",
|
||||
"Starting agent session",
|
||||
spec_dir=str(spec_dir),
|
||||
phase=phase.value,
|
||||
prompt_length=len(message),
|
||||
prompt_preview=message[:200] + "..." if len(message) > 200 else message,
|
||||
)
|
||||
print("Sending prompt to Claude Agent SDK...\n")
|
||||
|
||||
# Get task logger for this spec
|
||||
task_logger = get_task_logger(spec_dir)
|
||||
current_tool = None
|
||||
message_count = 0
|
||||
tool_count = 0
|
||||
|
||||
try:
|
||||
# Send the query
|
||||
debug("session", "Sending query to Claude SDK...")
|
||||
await client.query(message)
|
||||
debug_success("session", "Query sent successfully")
|
||||
|
||||
# Collect response text and show tool use
|
||||
response_text = ""
|
||||
debug("session", "Starting to receive response stream...")
|
||||
async for msg in client.receive_response():
|
||||
msg_type = type(msg).__name__
|
||||
message_count += 1
|
||||
debug_detailed(
|
||||
"session",
|
||||
f"Received message #{message_count}",
|
||||
msg_type=msg_type,
|
||||
)
|
||||
|
||||
# Handle AssistantMessage (text and tool use)
|
||||
if msg_type == "AssistantMessage" and hasattr(msg, "content"):
|
||||
@@ -366,6 +387,7 @@ async def run_agent_session(
|
||||
elif block_type == "ToolUseBlock" and hasattr(block, "name"):
|
||||
tool_name = block.name
|
||||
tool_input = None
|
||||
tool_count += 1
|
||||
|
||||
# Extract meaningful tool input for display
|
||||
if hasattr(block, "input") and block.input:
|
||||
@@ -386,6 +408,13 @@ async def run_agent_session(
|
||||
elif "path" in inp:
|
||||
tool_input = inp["path"]
|
||||
|
||||
debug(
|
||||
"session",
|
||||
f"Tool call #{tool_count}: {tool_name}",
|
||||
tool_input=tool_input,
|
||||
full_input=str(block.input)[:500] if hasattr(block, "input") else None,
|
||||
)
|
||||
|
||||
# Log tool start (handles printing too)
|
||||
if task_logger:
|
||||
task_logger.tool_start(
|
||||
@@ -413,6 +442,11 @@ async def run_agent_session(
|
||||
|
||||
# Check if command was blocked by security hook
|
||||
if "blocked" in str(result_content).lower():
|
||||
debug_error(
|
||||
"session",
|
||||
f"Tool BLOCKED: {current_tool}",
|
||||
result=str(result_content)[:300],
|
||||
)
|
||||
print(f" [BLOCKED] {result_content}", flush=True)
|
||||
if task_logger and current_tool:
|
||||
task_logger.tool_end(
|
||||
@@ -425,6 +459,11 @@ async def run_agent_session(
|
||||
elif is_error:
|
||||
# Show errors (truncated)
|
||||
error_str = str(result_content)[:500]
|
||||
debug_error(
|
||||
"session",
|
||||
f"Tool error: {current_tool}",
|
||||
error=error_str[:200],
|
||||
)
|
||||
print(f" [Error] {error_str}", flush=True)
|
||||
if task_logger and current_tool:
|
||||
# Store full error in detail for expandable view
|
||||
@@ -437,6 +476,11 @@ async def run_agent_session(
|
||||
)
|
||||
else:
|
||||
# Tool succeeded
|
||||
debug_detailed(
|
||||
"session",
|
||||
f"Tool success: {current_tool}",
|
||||
result_length=len(str(result_content)),
|
||||
)
|
||||
if verbose:
|
||||
result_str = str(result_content)[:200]
|
||||
print(f" [Done] {result_str}", flush=True)
|
||||
@@ -472,11 +516,32 @@ async def run_agent_session(
|
||||
|
||||
# Check if build is complete
|
||||
if is_build_complete(spec_dir):
|
||||
debug_success(
|
||||
"session",
|
||||
"Session completed - build is complete",
|
||||
message_count=message_count,
|
||||
tool_count=tool_count,
|
||||
response_length=len(response_text),
|
||||
)
|
||||
return "complete", response_text
|
||||
|
||||
debug_success(
|
||||
"session",
|
||||
"Session completed - continuing",
|
||||
message_count=message_count,
|
||||
tool_count=tool_count,
|
||||
response_length=len(response_text),
|
||||
)
|
||||
return "continue", response_text
|
||||
|
||||
except Exception as e:
|
||||
debug_error(
|
||||
"session",
|
||||
f"Session error: {e}",
|
||||
exception_type=type(e).__name__,
|
||||
message_count=message_count,
|
||||
tool_count=tool_count,
|
||||
)
|
||||
print(f"Error during agent session: {e}")
|
||||
if task_logger:
|
||||
task_logger.log_error(f"Session error: {e}", phase)
|
||||
|
||||
@@ -8,6 +8,7 @@ Runs QA fixer sessions to resolve issues identified by the reviewer.
|
||||
from pathlib import Path
|
||||
|
||||
from claude_agent_sdk import ClaudeSDKClient
|
||||
from debug import debug, debug_detailed, debug_error, debug_section, debug_success
|
||||
from task_logger import (
|
||||
LogEntryType,
|
||||
LogPhase,
|
||||
@@ -58,6 +59,14 @@ async def run_qa_fixer_session(
|
||||
- "fixed" if fixes were applied
|
||||
- "error" if an error occurred
|
||||
"""
|
||||
debug_section("qa_fixer", f"QA Fixer Session {fix_session}")
|
||||
debug(
|
||||
"qa_fixer",
|
||||
"Starting QA fixer session",
|
||||
spec_dir=str(spec_dir),
|
||||
fix_session=fix_session,
|
||||
)
|
||||
|
||||
print(f"\n{'=' * 70}")
|
||||
print(f" QA FIXER SESSION {fix_session}")
|
||||
print(" Applying fixes from QA_FIX_REQUEST.md...")
|
||||
@@ -66,14 +75,18 @@ async def run_qa_fixer_session(
|
||||
# Get task logger for streaming markers
|
||||
task_logger = get_task_logger(spec_dir)
|
||||
current_tool = None
|
||||
message_count = 0
|
||||
tool_count = 0
|
||||
|
||||
# Check that fix request file exists
|
||||
fix_request_file = spec_dir / "QA_FIX_REQUEST.md"
|
||||
if not fix_request_file.exists():
|
||||
debug_error("qa_fixer", "QA_FIX_REQUEST.md not found")
|
||||
return "error", "QA_FIX_REQUEST.md not found"
|
||||
|
||||
# Load fixer prompt
|
||||
prompt = load_qa_fixer_prompt()
|
||||
debug_detailed("qa_fixer", "Loaded QA fixer prompt", prompt_length=len(prompt))
|
||||
|
||||
# Add session context - use full path so agent can find files
|
||||
prompt += f"\n\n---\n\n**Fix Session**: {fix_session}\n"
|
||||
@@ -83,11 +96,20 @@ async def run_qa_fixer_session(
|
||||
prompt += f"The fix request file is at: `{spec_dir}/QA_FIX_REQUEST.md`\n"
|
||||
|
||||
try:
|
||||
debug("qa_fixer", "Sending query to Claude SDK...")
|
||||
await client.query(prompt)
|
||||
debug_success("qa_fixer", "Query sent successfully")
|
||||
|
||||
response_text = ""
|
||||
debug("qa_fixer", "Starting to receive response stream...")
|
||||
async for msg in client.receive_response():
|
||||
msg_type = type(msg).__name__
|
||||
message_count += 1
|
||||
debug_detailed(
|
||||
"qa_fixer",
|
||||
f"Received message #{message_count}",
|
||||
msg_type=msg_type,
|
||||
)
|
||||
|
||||
if msg_type == "AssistantMessage" and hasattr(msg, "content"):
|
||||
for block in msg.content:
|
||||
@@ -107,6 +129,7 @@ async def run_qa_fixer_session(
|
||||
elif block_type == "ToolUseBlock" and hasattr(block, "name"):
|
||||
tool_name = block.name
|
||||
tool_input = None
|
||||
tool_count += 1
|
||||
|
||||
if hasattr(block, "input") and block.input:
|
||||
inp = block.input
|
||||
@@ -122,6 +145,12 @@ async def run_qa_fixer_session(
|
||||
cmd = cmd[:47] + "..."
|
||||
tool_input = cmd
|
||||
|
||||
debug(
|
||||
"qa_fixer",
|
||||
f"Tool call #{tool_count}: {tool_name}",
|
||||
tool_input=tool_input,
|
||||
)
|
||||
|
||||
# Log tool start (handles printing)
|
||||
if task_logger:
|
||||
task_logger.tool_start(
|
||||
@@ -150,6 +179,11 @@ async def run_qa_fixer_session(
|
||||
result_content = getattr(block, "content", "")
|
||||
|
||||
if is_error:
|
||||
debug_error(
|
||||
"qa_fixer",
|
||||
f"Tool error: {current_tool}",
|
||||
error=str(result_content)[:200],
|
||||
)
|
||||
error_str = str(result_content)[:500]
|
||||
print(f" [Error] {error_str}", flush=True)
|
||||
if task_logger and current_tool:
|
||||
@@ -162,6 +196,11 @@ async def run_qa_fixer_session(
|
||||
phase=LogPhase.VALIDATION,
|
||||
)
|
||||
else:
|
||||
debug_detailed(
|
||||
"qa_fixer",
|
||||
f"Tool success: {current_tool}",
|
||||
result_length=len(str(result_content)),
|
||||
)
|
||||
if verbose:
|
||||
result_str = str(result_content)[:200]
|
||||
print(f" [Done] {result_str}", flush=True)
|
||||
@@ -193,13 +232,28 @@ async def run_qa_fixer_session(
|
||||
|
||||
# Check if fixes were applied
|
||||
status = get_qa_signoff_status(spec_dir)
|
||||
debug(
|
||||
"qa_fixer",
|
||||
"Fixer session completed",
|
||||
message_count=message_count,
|
||||
tool_count=tool_count,
|
||||
response_length=len(response_text),
|
||||
ready_for_revalidation=status.get("ready_for_qa_revalidation") if status else False,
|
||||
)
|
||||
if status and status.get("ready_for_qa_revalidation"):
|
||||
debug_success("qa_fixer", "Fixes applied, ready for QA revalidation")
|
||||
return "fixed", response_text
|
||||
else:
|
||||
# Fixer didn't update the status properly, but we'll trust it worked
|
||||
debug_success("qa_fixer", "Fixes assumed applied (status not updated)")
|
||||
return "fixed", response_text
|
||||
|
||||
except Exception as e:
|
||||
debug_error(
|
||||
"qa_fixer",
|
||||
f"Fixer session exception: {e}",
|
||||
exception_type=type(e).__name__,
|
||||
)
|
||||
print(f"Error during fixer session: {e}")
|
||||
if task_logger:
|
||||
task_logger.log_error(f"QA fixer error: {e}", LogPhase.VALIDATION)
|
||||
|
||||
@@ -10,6 +10,7 @@ import time as time_module
|
||||
from pathlib import Path
|
||||
|
||||
from client import create_client
|
||||
from debug import debug, debug_error, debug_section, debug_success, debug_warning
|
||||
from linear_updater import (
|
||||
LinearTaskState,
|
||||
is_linear_enabled,
|
||||
@@ -79,6 +80,16 @@ async def run_qa_validation_loop(
|
||||
Returns:
|
||||
True if QA approved, False otherwise
|
||||
"""
|
||||
debug_section("qa_loop", "QA Validation Loop")
|
||||
debug(
|
||||
"qa_loop",
|
||||
"Starting QA validation loop",
|
||||
project_dir=str(project_dir),
|
||||
spec_dir=str(spec_dir),
|
||||
model=model,
|
||||
max_iterations=MAX_QA_ITERATIONS,
|
||||
)
|
||||
|
||||
print("\n" + "=" * 70)
|
||||
print(" QA VALIDATION LOOP")
|
||||
print(" Self-validating quality assurance")
|
||||
@@ -89,13 +100,16 @@ async def run_qa_validation_loop(
|
||||
|
||||
# Verify build is complete
|
||||
if not is_build_complete(spec_dir):
|
||||
debug_warning("qa_loop", "Build is not complete, cannot run QA")
|
||||
print("\n❌ Build is not complete. Cannot run QA validation.")
|
||||
completed, total = count_subtasks(spec_dir)
|
||||
debug("qa_loop", "Build progress", completed=completed, total=total)
|
||||
print(f" Progress: {completed}/{total} subtasks completed")
|
||||
return False
|
||||
|
||||
# Check if already approved
|
||||
if is_qa_approved(spec_dir):
|
||||
debug_success("qa_loop", "Build already approved by QA")
|
||||
print("\n✅ Build already approved by QA.")
|
||||
return True
|
||||
|
||||
@@ -127,20 +141,43 @@ async def run_qa_validation_loop(
|
||||
qa_iteration += 1
|
||||
iteration_start = time_module.time()
|
||||
|
||||
debug_section("qa_loop", f"QA Iteration {qa_iteration}")
|
||||
debug(
|
||||
"qa_loop",
|
||||
f"Starting iteration {qa_iteration}/{MAX_QA_ITERATIONS}",
|
||||
iteration=qa_iteration,
|
||||
max_iterations=MAX_QA_ITERATIONS,
|
||||
)
|
||||
|
||||
print(f"\n--- QA Iteration {qa_iteration}/{MAX_QA_ITERATIONS} ---")
|
||||
|
||||
# Run QA reviewer
|
||||
debug("qa_loop", "Creating client for QA reviewer session...")
|
||||
client = create_client(project_dir, spec_dir, model)
|
||||
|
||||
async with client:
|
||||
debug("qa_loop", "Running QA reviewer agent session...")
|
||||
status, response = await run_qa_agent_session(
|
||||
client, spec_dir, qa_iteration, MAX_QA_ITERATIONS, verbose
|
||||
)
|
||||
|
||||
iteration_duration = time_module.time() - iteration_start
|
||||
debug(
|
||||
"qa_loop",
|
||||
f"QA reviewer session completed",
|
||||
status=status,
|
||||
duration_seconds=f"{iteration_duration:.1f}",
|
||||
response_length=len(response),
|
||||
)
|
||||
|
||||
if status == "approved":
|
||||
# Record successful iteration
|
||||
debug_success(
|
||||
"qa_loop",
|
||||
"QA APPROVED",
|
||||
iteration=qa_iteration,
|
||||
duration=f"{iteration_duration:.1f}s",
|
||||
)
|
||||
record_iteration(spec_dir, qa_iteration, "approved", [], iteration_duration)
|
||||
|
||||
print("\n" + "=" * 70)
|
||||
@@ -168,11 +205,23 @@ async def run_qa_validation_loop(
|
||||
return True
|
||||
|
||||
elif status == "rejected":
|
||||
debug_warning(
|
||||
"qa_loop",
|
||||
"QA REJECTED",
|
||||
iteration=qa_iteration,
|
||||
duration=f"{iteration_duration:.1f}s",
|
||||
)
|
||||
print(f"\n❌ QA found issues. Iteration {qa_iteration}/{MAX_QA_ITERATIONS}")
|
||||
|
||||
# Get issues from QA report
|
||||
qa_status = get_qa_signoff_status(spec_dir)
|
||||
current_issues = qa_status.get("issues_found", []) if qa_status else []
|
||||
debug(
|
||||
"qa_loop",
|
||||
"Issues found by QA",
|
||||
issue_count=len(current_issues),
|
||||
issues=current_issues[:3] if current_issues else [], # Show first 3
|
||||
)
|
||||
|
||||
# Record rejected iteration
|
||||
record_iteration(
|
||||
@@ -188,6 +237,12 @@ async def run_qa_validation_loop(
|
||||
if has_recurring:
|
||||
from .report import RECURRING_ISSUE_THRESHOLD
|
||||
|
||||
debug_error(
|
||||
"qa_loop",
|
||||
"Recurring issues detected - escalating to human",
|
||||
recurring_count=len(recurring_issues),
|
||||
threshold=RECURRING_ISSUE_THRESHOLD,
|
||||
)
|
||||
print(
|
||||
f"\n⚠️ Recurring issues detected ({len(recurring_issues)} issue(s) appeared {RECURRING_ISSUE_THRESHOLD}+ times)"
|
||||
)
|
||||
@@ -224,6 +279,7 @@ async def run_qa_validation_loop(
|
||||
break
|
||||
|
||||
# Run fixer
|
||||
debug("qa_loop", "Starting QA fixer session...")
|
||||
print("\nRunning QA Fixer Agent...")
|
||||
|
||||
fix_client = create_client(project_dir, spec_dir, model)
|
||||
@@ -233,7 +289,15 @@ async def run_qa_validation_loop(
|
||||
fix_client, spec_dir, qa_iteration, verbose
|
||||
)
|
||||
|
||||
debug(
|
||||
"qa_loop",
|
||||
"QA fixer session completed",
|
||||
fix_status=fix_status,
|
||||
response_length=len(fix_response),
|
||||
)
|
||||
|
||||
if fix_status == "error":
|
||||
debug_error("qa_loop", f"Fixer error: {fix_response[:200]}")
|
||||
print(f"\n❌ Fixer encountered error: {fix_response}")
|
||||
record_iteration(
|
||||
spec_dir,
|
||||
@@ -243,9 +307,11 @@ async def run_qa_validation_loop(
|
||||
)
|
||||
break
|
||||
|
||||
debug_success("qa_loop", "Fixes applied, re-running QA validation")
|
||||
print("\n✅ Fixes applied. Re-running QA validation...")
|
||||
|
||||
elif status == "error":
|
||||
debug_error("qa_loop", f"QA session error: {response[:200]}")
|
||||
print(f"\n❌ QA error: {response}")
|
||||
record_iteration(
|
||||
spec_dir,
|
||||
@@ -256,6 +322,12 @@ async def run_qa_validation_loop(
|
||||
print("Retrying...")
|
||||
|
||||
# Max iterations reached without approval
|
||||
debug_error(
|
||||
"qa_loop",
|
||||
"QA VALIDATION INCOMPLETE - max iterations reached",
|
||||
iterations=qa_iteration,
|
||||
max_iterations=MAX_QA_ITERATIONS,
|
||||
)
|
||||
print("\n" + "=" * 70)
|
||||
print(" ⚠️ QA VALIDATION INCOMPLETE")
|
||||
print("=" * 70)
|
||||
@@ -265,6 +337,13 @@ async def run_qa_validation_loop(
|
||||
# Show iteration summary
|
||||
history = get_iteration_history(spec_dir)
|
||||
summary = get_recurring_issue_summary(history)
|
||||
debug(
|
||||
"qa_loop",
|
||||
"QA loop final summary",
|
||||
total_iterations=len(history),
|
||||
total_issues=summary.get("total_issues", 0),
|
||||
unique_issues=summary.get("unique_issues", 0),
|
||||
)
|
||||
if summary["total_issues"] > 0:
|
||||
print("\n📊 Iteration Summary:")
|
||||
print(f" Total iterations: {len(history)}")
|
||||
|
||||
@@ -9,6 +9,7 @@ acceptance criteria.
|
||||
from pathlib import Path
|
||||
|
||||
from claude_agent_sdk import ClaudeSDKClient
|
||||
from debug import debug, debug_detailed, debug_error, debug_section, debug_success
|
||||
from task_logger import (
|
||||
LogEntryType,
|
||||
LogPhase,
|
||||
@@ -62,6 +63,15 @@ async def run_qa_agent_session(
|
||||
- "rejected" if QA finds issues
|
||||
- "error" if an error occurred
|
||||
"""
|
||||
debug_section("qa_reviewer", f"QA Reviewer Session {qa_session}")
|
||||
debug(
|
||||
"qa_reviewer",
|
||||
"Starting QA reviewer session",
|
||||
spec_dir=str(spec_dir),
|
||||
qa_session=qa_session,
|
||||
max_iterations=max_iterations,
|
||||
)
|
||||
|
||||
print(f"\n{'=' * 70}")
|
||||
print(f" QA REVIEWER SESSION {qa_session}")
|
||||
print(" Validating all acceptance criteria...")
|
||||
@@ -70,9 +80,12 @@ async def run_qa_agent_session(
|
||||
# Get task logger for streaming markers
|
||||
task_logger = get_task_logger(spec_dir)
|
||||
current_tool = None
|
||||
message_count = 0
|
||||
tool_count = 0
|
||||
|
||||
# Load QA prompt
|
||||
prompt = load_qa_reviewer_prompt()
|
||||
debug_detailed("qa_reviewer", "Loaded QA reviewer prompt", prompt_length=len(prompt))
|
||||
|
||||
# Add session context - use full path so agent can find files
|
||||
prompt += f"\n\n---\n\n**QA Session**: {qa_session}\n"
|
||||
@@ -83,11 +96,20 @@ async def run_qa_agent_session(
|
||||
prompt += f"Use the full path when reading files, e.g.: `cat {spec_dir}/spec.md`\n"
|
||||
|
||||
try:
|
||||
debug("qa_reviewer", "Sending query to Claude SDK...")
|
||||
await client.query(prompt)
|
||||
debug_success("qa_reviewer", "Query sent successfully")
|
||||
|
||||
response_text = ""
|
||||
debug("qa_reviewer", "Starting to receive response stream...")
|
||||
async for msg in client.receive_response():
|
||||
msg_type = type(msg).__name__
|
||||
message_count += 1
|
||||
debug_detailed(
|
||||
"qa_reviewer",
|
||||
f"Received message #{message_count}",
|
||||
msg_type=msg_type,
|
||||
)
|
||||
|
||||
if msg_type == "AssistantMessage" and hasattr(msg, "content"):
|
||||
for block in msg.content:
|
||||
@@ -107,6 +129,7 @@ async def run_qa_agent_session(
|
||||
elif block_type == "ToolUseBlock" and hasattr(block, "name"):
|
||||
tool_name = block.name
|
||||
tool_input = None
|
||||
tool_count += 1
|
||||
|
||||
# Extract tool input for display
|
||||
if hasattr(block, "input") and block.input:
|
||||
@@ -120,6 +143,12 @@ async def run_qa_agent_session(
|
||||
elif "pattern" in inp:
|
||||
tool_input = f"pattern: {inp['pattern']}"
|
||||
|
||||
debug(
|
||||
"qa_reviewer",
|
||||
f"Tool call #{tool_count}: {tool_name}",
|
||||
tool_input=tool_input,
|
||||
)
|
||||
|
||||
# Log tool start (handles printing)
|
||||
if task_logger:
|
||||
task_logger.tool_start(
|
||||
@@ -148,6 +177,11 @@ async def run_qa_agent_session(
|
||||
result_content = getattr(block, "content", "")
|
||||
|
||||
if is_error:
|
||||
debug_error(
|
||||
"qa_reviewer",
|
||||
f"Tool error: {current_tool}",
|
||||
error=str(result_content)[:200],
|
||||
)
|
||||
error_str = str(result_content)[:500]
|
||||
print(f" [Error] {error_str}", flush=True)
|
||||
if task_logger and current_tool:
|
||||
@@ -160,6 +194,11 @@ async def run_qa_agent_session(
|
||||
phase=LogPhase.VALIDATION,
|
||||
)
|
||||
else:
|
||||
debug_detailed(
|
||||
"qa_reviewer",
|
||||
f"Tool success: {current_tool}",
|
||||
result_length=len(str(result_content)),
|
||||
)
|
||||
if verbose:
|
||||
result_str = str(result_content)[:200]
|
||||
print(f" [Done] {result_str}", flush=True)
|
||||
@@ -191,15 +230,31 @@ async def run_qa_agent_session(
|
||||
|
||||
# Check the QA result from implementation_plan.json
|
||||
status = get_qa_signoff_status(spec_dir)
|
||||
debug(
|
||||
"qa_reviewer",
|
||||
"QA session completed",
|
||||
message_count=message_count,
|
||||
tool_count=tool_count,
|
||||
response_length=len(response_text),
|
||||
qa_status=status.get("status") if status else "unknown",
|
||||
)
|
||||
if status and status.get("status") == "approved":
|
||||
debug_success("qa_reviewer", "QA APPROVED")
|
||||
return "approved", response_text
|
||||
elif status and status.get("status") == "rejected":
|
||||
debug_error("qa_reviewer", "QA REJECTED")
|
||||
return "rejected", response_text
|
||||
else:
|
||||
# Agent didn't update the status properly
|
||||
debug_error("qa_reviewer", "QA agent did not update implementation_plan.json")
|
||||
return "error", "QA agent did not update implementation_plan.json"
|
||||
|
||||
except Exception as e:
|
||||
debug_error(
|
||||
"qa_reviewer",
|
||||
f"QA session exception: {e}",
|
||||
exception_type=type(e).__name__,
|
||||
)
|
||||
print(f"Error during QA session: {e}")
|
||||
if task_logger:
|
||||
task_logger.log_error(f"QA session error: {e}", LogPhase.VALIDATION)
|
||||
|
||||
@@ -91,6 +91,7 @@ if env_file.exists():
|
||||
elif dev_env_file.exists():
|
||||
load_dotenv(dev_env_file)
|
||||
|
||||
from debug import debug, debug_error, debug_section, debug_success
|
||||
from review import ReviewState
|
||||
from spec import SpecOrchestrator
|
||||
from ui import Icons, highlight, icon, muted, print_section, print_status
|
||||
@@ -98,6 +99,7 @@ from ui import Icons, highlight, icon, muted, print_section, print_status
|
||||
|
||||
def main():
|
||||
"""CLI entry point."""
|
||||
debug_section("spec_runner", "Spec Runner CLI")
|
||||
import argparse
|
||||
|
||||
parser = argparse.ArgumentParser(
|
||||
@@ -232,6 +234,18 @@ Examples:
|
||||
f"\n{icon(Icons.GEAR)} Note: --dev flag is deprecated. All specs now go to .auto-claude/specs/\n"
|
||||
)
|
||||
|
||||
debug(
|
||||
"spec_runner",
|
||||
"Creating spec orchestrator",
|
||||
project_dir=str(project_dir),
|
||||
task_description=task_description[:200] if task_description else None,
|
||||
model=args.model,
|
||||
complexity_override=args.complexity,
|
||||
use_ai_assessment=not args.no_ai_assessment,
|
||||
interactive=args.interactive or not task_description,
|
||||
auto_approve=args.auto_approve,
|
||||
)
|
||||
|
||||
orchestrator = SpecOrchestrator(
|
||||
project_dir=project_dir,
|
||||
task_description=task_description,
|
||||
@@ -244,6 +258,7 @@ Examples:
|
||||
)
|
||||
|
||||
try:
|
||||
debug("spec_runner", "Starting spec orchestrator run...")
|
||||
success = asyncio.run(
|
||||
orchestrator.run(
|
||||
interactive=args.interactive or not task_description,
|
||||
@@ -252,13 +267,18 @@ Examples:
|
||||
)
|
||||
|
||||
if not success:
|
||||
debug_error("spec_runner", "Spec creation failed")
|
||||
sys.exit(1)
|
||||
|
||||
debug_success("spec_runner", "Spec creation succeeded", spec_dir=str(orchestrator.spec_dir))
|
||||
|
||||
# Auto-start build unless --no-build is specified
|
||||
if not args.no_build:
|
||||
debug("spec_runner", "Checking if spec is approved for build...")
|
||||
# Verify spec is approved before starting build (defensive check)
|
||||
review_state = ReviewState.load(orchestrator.spec_dir)
|
||||
if not review_state.is_approved():
|
||||
debug_error("spec_runner", "Spec not approved - cannot start build")
|
||||
print()
|
||||
print_status("Build cannot start: spec not approved.", "error")
|
||||
print()
|
||||
@@ -276,6 +296,7 @@ Examples:
|
||||
print(f" {highlight(example_cmd)}")
|
||||
sys.exit(1)
|
||||
|
||||
debug_success("spec_runner", "Spec approved - starting build")
|
||||
print()
|
||||
print_section("STARTING BUILD", Icons.LIGHTNING)
|
||||
print()
|
||||
@@ -300,6 +321,11 @@ Examples:
|
||||
if args.model != "claude-opus-4-5-20251101":
|
||||
run_cmd.extend(["--model", args.model])
|
||||
|
||||
debug(
|
||||
"spec_runner",
|
||||
"Executing run.py for build",
|
||||
command=" ".join(run_cmd),
|
||||
)
|
||||
print(f" {muted('Running:')} {' '.join(run_cmd)}")
|
||||
print()
|
||||
|
||||
@@ -309,6 +335,7 @@ Examples:
|
||||
sys.exit(0)
|
||||
|
||||
except KeyboardInterrupt:
|
||||
debug_error("spec_runner", "Spec creation interrupted by user")
|
||||
print("\n\nSpec creation interrupted.")
|
||||
print(
|
||||
f"To continue: python auto-claude/spec_runner.py --continue {orchestrator.spec_dir.name}"
|
||||
|
||||
@@ -13,6 +13,7 @@ from ui.capabilities import configure_safe_encoding
|
||||
configure_safe_encoding()
|
||||
|
||||
from client import create_client
|
||||
from debug import debug, debug_detailed, debug_error, debug_section, debug_success
|
||||
from task_logger import (
|
||||
LogEntryType,
|
||||
LogPhase,
|
||||
@@ -59,13 +60,29 @@ class AgentRunner:
|
||||
Returns:
|
||||
Tuple of (success, response_text)
|
||||
"""
|
||||
debug_section("agent_runner", f"Spec Agent - {prompt_file}")
|
||||
debug(
|
||||
"agent_runner",
|
||||
"Running spec creation agent",
|
||||
prompt_file=prompt_file,
|
||||
spec_dir=str(self.spec_dir),
|
||||
model=self.model,
|
||||
interactive=interactive,
|
||||
)
|
||||
|
||||
prompt_path = Path(__file__).parent.parent.parent / "prompts" / prompt_file
|
||||
|
||||
if not prompt_path.exists():
|
||||
debug_error("agent_runner", f"Prompt file not found: {prompt_path}")
|
||||
return False, f"Prompt not found: {prompt_path}"
|
||||
|
||||
# Load prompt
|
||||
prompt = prompt_path.read_text()
|
||||
debug_detailed(
|
||||
"agent_runner",
|
||||
"Loaded prompt file",
|
||||
prompt_length=len(prompt),
|
||||
)
|
||||
|
||||
# Add context
|
||||
prompt += f"\n\n---\n\n**Spec Directory**: {self.spec_dir}\n"
|
||||
@@ -73,19 +90,36 @@ class AgentRunner:
|
||||
|
||||
if additional_context:
|
||||
prompt += f"\n{additional_context}\n"
|
||||
debug_detailed(
|
||||
"agent_runner",
|
||||
"Added additional context",
|
||||
context_length=len(additional_context),
|
||||
)
|
||||
|
||||
# Create client
|
||||
debug("agent_runner", "Creating Claude SDK client...")
|
||||
client = create_client(self.project_dir, self.spec_dir, self.model)
|
||||
|
||||
current_tool = None
|
||||
message_count = 0
|
||||
tool_count = 0
|
||||
|
||||
try:
|
||||
async with client:
|
||||
debug("agent_runner", "Sending query to Claude SDK...")
|
||||
await client.query(prompt)
|
||||
debug_success("agent_runner", "Query sent successfully")
|
||||
|
||||
response_text = ""
|
||||
debug("agent_runner", "Starting to receive response stream...")
|
||||
async for msg in client.receive_response():
|
||||
msg_type = type(msg).__name__
|
||||
message_count += 1
|
||||
debug_detailed(
|
||||
"agent_runner",
|
||||
f"Received message #{message_count}",
|
||||
msg_type=msg_type,
|
||||
)
|
||||
|
||||
if msg_type == "AssistantMessage" and hasattr(msg, "content"):
|
||||
for block in msg.content:
|
||||
@@ -105,6 +139,7 @@ class AgentRunner:
|
||||
):
|
||||
tool_name = block.name
|
||||
tool_input = None
|
||||
tool_count += 1
|
||||
|
||||
# Extract meaningful tool input for display
|
||||
if hasattr(block, "input") and block.input:
|
||||
@@ -112,6 +147,12 @@ class AgentRunner:
|
||||
block.input
|
||||
)
|
||||
|
||||
debug(
|
||||
"agent_runner",
|
||||
f"Tool call #{tool_count}: {tool_name}",
|
||||
tool_input=tool_input,
|
||||
)
|
||||
|
||||
if self.task_logger:
|
||||
self.task_logger.tool_start(
|
||||
tool_name,
|
||||
@@ -129,6 +170,18 @@ class AgentRunner:
|
||||
if block_type == "ToolResultBlock":
|
||||
is_error = getattr(block, "is_error", False)
|
||||
result_content = getattr(block, "content", "")
|
||||
if is_error:
|
||||
debug_error(
|
||||
"agent_runner",
|
||||
f"Tool error: {current_tool}",
|
||||
error=str(result_content)[:200],
|
||||
)
|
||||
else:
|
||||
debug_detailed(
|
||||
"agent_runner",
|
||||
f"Tool success: {current_tool}",
|
||||
result_length=len(str(result_content)),
|
||||
)
|
||||
if self.task_logger and current_tool:
|
||||
detail_content = self._get_tool_detail_content(
|
||||
current_tool, result_content
|
||||
@@ -142,9 +195,21 @@ class AgentRunner:
|
||||
current_tool = None
|
||||
|
||||
print()
|
||||
debug_success(
|
||||
"agent_runner",
|
||||
"Agent session completed successfully",
|
||||
message_count=message_count,
|
||||
tool_count=tool_count,
|
||||
response_length=len(response_text),
|
||||
)
|
||||
return True, response_text
|
||||
|
||||
except Exception as e:
|
||||
debug_error(
|
||||
"agent_runner",
|
||||
f"Agent session error: {e}",
|
||||
exception_type=type(e).__name__,
|
||||
)
|
||||
if self.task_logger:
|
||||
self.task_logger.log_error(f"Agent error: {e}", LogPhase.PLANNING)
|
||||
return False, str(e)
|
||||
|
||||
Reference in New Issue
Block a user