Skip to content

refactor: complete project-wide migration to structured logging #52

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
dkargatzis wants to merge 1 commit into
base: main
Choose a base branch
from
Open

refactor: complete project-wide migration to structured logging #52

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
44 changes: 20 additions & 24 deletions src/agents/acknowledgment_agent/agent.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,9 +2,9 @@
Intelligent Acknowledgment Agent for evaluating violation acknowledgment requests.
"""

import logging
from typing import Any

import structlog
from langchain_core.messages import HumanMessage, SystemMessage
from langgraph.graph import StateGraph

Expand All @@ -13,7 +13,7 @@
from src.agents.base import AgentResult, BaseAgent
from src.integrations.providers import get_chat_model

logger = logging.getLogger(__name__)
logger = structlog.get_logger()


class AcknowledgmentAgent(BaseAgent):
Expand All @@ -31,7 +31,7 @@ def __init__(self, max_retries: int = 3, timeout: float = 30.0):
# Call super class __init__ first
super().__init__(max_retries=max_retries, agent_name="acknowledgment_agent")
self.timeout = timeout
logger.info(f"🧠 Acknowledgment agent initialized with timeout: {timeout}s")
logger.info("acknowledgment_agent_initialized_with_timeout_s", timeout=timeout)

def _build_graph(self) -> Any:
"""
Expand Down Expand Up @@ -63,7 +63,7 @@ async def _evaluate_node(self, state: Any) -> AgentResult:
)
return result
except Exception as e:
logger.error(f"🧠 Error in evaluation node: {e}")
logger.error("error_in_evaluation_node", e=e)
return AgentResult(success=False, message=f"Evaluation failed: {str(e)}", data={"error": str(e)})

@staticmethod
Expand All @@ -86,9 +86,9 @@ async def evaluate_acknowledgment(
Intelligently evaluate an acknowledgment request based on rule descriptions and context.
"""
try:
logger.info(f"🧠 Evaluating acknowledgment request from {commenter}")
logger.info(f"🧠 Reason: {acknowledgment_reason}")
logger.info(f"🧠 Violations to evaluate: {len(violations)}")
logger.info("evaluating_acknowledgment_request_from", commenter=commenter)
logger.info("acknowledgment_reason", reason=acknowledgment_reason)
logger.info("violations_to_evaluate", count=len(violations))
Comment on lines +89 to +91
Copy link

@coderabbitai coderabbitai bot Feb 26, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Potential issue | 🟠 Major

Raw user input and raw reasoning are being logged.

Line 90 logs acknowledgment_reason, Line 181 logs full reasoning text, and Line 203 logs full traceback text. These can expose secrets/PII or internal reasoning content; log sanitized summaries/metadata instead.

Based on learnings: "Strip secrets/PII from agent prompts; scope tools; keep raw reasoning out of logs (store summaries only)".

Also applies to: 181-183, 203-203

🤖 Prompt for AI Agents 
Verify each finding against the current code and only fix it if needed.

In `@src/agents/acknowledgment_agent/agent.py` around lines 89 - 91, Logging
currently emits raw user input and internal reasoning (e.g.,
acknowledgment_reason, full reasoning_text, and full traceback_text). Replace
direct logger.info calls that log acknowledgment_reason, reasoning_text, and
traceback_text with sanitized summaries: redact PII/secrets, log a short hash or
length and a redaction flag (e.g., "reason_redacted", "reason_length",
"traceback_summary") and/or a safe metadata tuple (count of violations,
categories) instead of full content; implement or call an existing
sanitize/redact helper before logging and ensure
logger.info("violations_to_evaluate", count=len(violations)) remains but that
any strings passed (acknowledgment_reason, reasoning_text, traceback_text) are
replaced by their sanitized summaries in the same function/agent (agent.py)
where these variables are constructed/used.


# Validate inputs
if not acknowledgment_reason or not violations:
Expand All @@ -102,7 +102,7 @@ async def evaluate_acknowledgment(
evaluation_prompt = create_evaluation_prompt(acknowledgment_reason, violations, pr_data, commenter, rules)

# Get LLM evaluation with structured output
logger.info("🧠 Requesting LLM evaluation with structured output...")
logger.info("requesting_llm_evaluation_with_structured_output")

# Use the same pattern as other agents: direct get_chat_model call
llm = get_chat_model(agent="acknowledgment_agent")
Expand All @@ -112,12 +112,12 @@ async def evaluate_acknowledgment(
structured_result = await self._execute_with_timeout(structured_llm.ainvoke(messages), timeout=self.timeout)

if not structured_result:
logger.error("🧠 Empty LLM response received")
logger.error("empty_llm_response_received")
return AgentResult(
success=False, message="Empty response from LLM", data={"error": "LLM returned empty response"}
)

logger.info("🧠 Successfully received structured LLM evaluation result")
logger.info("successfully_received_structured_llm_evaluation_result")

# Map LLM decisions back to original violations using rule_description
acknowledgable_violations = []
Expand All @@ -138,11 +138,9 @@ async def evaluate_acknowledgment(
# Fallback: try to find by rule_description
original_violation = self._find_violation_by_rule_description(rule_description, violations)
if original_violation:
logger.info(f"🧠 Found violation by rule description: '{rule_description}'")
logger.info("found_violation_by_rule_description", rule_description=rule_description)
else:
logger.warning(
f"🧠 LLM returned rule_description '{rule_description}' not found in original violations"
)
logger.warning("llm_returned_ruledescription_not_found_in", rule_description=rule_description)

if original_violation:
violation_copy = original_violation.copy()
Expand All @@ -168,24 +166,22 @@ async def evaluate_acknowledgment(
# Fallback: try to find by rule_description
original_violation = self._find_violation_by_rule_description(rule_description, violations)
if original_violation:
logger.info(f"🧠 Found violation by rule description: '{rule_description}'")
logger.info("found_violation_by_rule_description", rule_description=rule_description)
else:
logger.warning(
f"🧠 LLM returned rule_description '{rule_description}' not found in original violations"
)
logger.warning("llm_returned_ruledescription_not_found_in", rule_description=rule_description)

if original_violation:
violation_copy = original_violation.copy()
# Add fix-specific fields
violation_copy.update({"fix_reason": llm_violation.reason, "priority": llm_violation.priority})
require_fixes.append(violation_copy)

logger.info("🧠 Intelligent evaluation completed:")
logger.info(f" Valid: {structured_result.is_valid}")
logger.info(f" Reasoning: {structured_result.reasoning}")
logger.info("intelligent_evaluation_completed")
logger.info("valid", is_valid=structured_result.is_valid)
logger.info("reasoning", reasoning=structured_result.reasoning)
logger.info(f" Acknowledged violations: {len(acknowledgable_violations)}")
logger.info(f" Require fixes: {len(require_fixes)}")
logger.info(f" Confidence: {structured_result.confidence}")
logger.info("confidence", confidence=structured_result.confidence)

return AgentResult(
success=True,
Expand All @@ -201,7 +197,7 @@ async def evaluate_acknowledgment(
)

except Exception as e:
logger.error(f"🧠 Error in acknowledgment evaluation: {e}")
logger.error("error_in_acknowledgment_evaluation", e=e)
import traceback

logger.error(f"🧠 Traceback: {traceback.format_exc()}")
Expand All @@ -228,7 +224,7 @@ async def execute(self, **kwargs: Any) -> AgentResult:
rules=rules,
)

logger.warning("🧠 execute() method called on AcknowledgmentAgent with missing arguments")
logger.warning("execute_method_called_on_acknowledgmentagent_with")
return AgentResult(
success=False, message="AcknowledgmentAgent requires specific arguments for execute()", data={}
)
19 changes: 10 additions & 9 deletions src/agents/acknowledgment_agent/test_agent.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,12 +6,13 @@
import logging

import pytest
import structlog

from src.agents.acknowledgment_agent.agent import AcknowledgmentAgent

# Set up logging
logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(__name__)
logger = structlog.get_logger()


@pytest.mark.asyncio
Expand Down Expand Up @@ -72,7 +73,7 @@ async def test_acknowledgment_agent() -> None:
},
]

logger.info("🧠 Testing Intelligent Acknowledgment Agent...")
logger.info("testing_intelligent_acknowledgment_agent")

try:
# Test evaluation
Expand All @@ -85,7 +86,7 @@ async def test_acknowledgment_agent() -> None:
)

if result.success:
logger.info("✅ Acknowledgment evaluation completed successfully")
logger.info("acknowledgment_evaluation_completed_successfully")
logger.info(f" Valid: {result.data.get('is_valid', False)}")
logger.info(f" Reasoning: {result.data.get('reasoning', 'No reasoning')}")
logger.info(f" Acknowledged violations: {len(result.data.get('acknowledgable_violations', []))}")
Expand All @@ -94,25 +95,25 @@ async def test_acknowledgment_agent() -> None:

# Print detailed results
if result.data.get("acknowledgable_violations"):
logger.info("\n📋 Acknowledged Violations:")
logger.info("n_acknowledged_violations")
for violation in result.data["acknowledgable_violations"]:
logger.info(f" • {violation.get('rule_name')} - {violation.get('reason')}")

if result.data.get("require_fixes"):
logger.info("\n⚠️ Violations Requiring Fixes:")
logger.info("n_violations_requiring_fixes")
for violation in result.data["require_fixes"]:
logger.info(f" • {violation.get('rule_name')} - {violation.get('reason')}")

if result.data.get("recommendations"):
logger.info("\n💡 Recommendations:")
logger.info("n_recommendations")
for rec in result.data["recommendations"]:
logger.info(f" • {rec}")
logger.info("event", rec=rec)

else:
logger.error(f"❌ Acknowledgment evaluation failed: {result.message}")
logger.error("acknowledgment_evaluation_failed", message=result.message)

except Exception as e:
logger.error(f"❌ Test failed with error: {e}")
logger.error("test_failed_with_error", e=e)


if __name__ == "__main__":
Expand Down
11 changes: 8 additions & 3 deletions src/agents/base.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,15 +2,15 @@
Base agent classes and utilities for agents.
"""

import logging
from abc import ABC, abstractmethod
from typing import Any, TypeVar, cast

import structlog
from pydantic import BaseModel, Field

from src.core.utils.timeout import execute_with_timeout

logger = logging.getLogger(__name__)
logger = structlog.get_logger()

T = TypeVar("T")

Expand Down Expand Up @@ -44,7 +44,12 @@ def __init__(self, max_retries: int = 3, retry_delay: float = 1.0, agent_name: s

self.llm = get_chat_model(agent=agent_name)
self.graph = self._build_graph()
logger.info(f"🔧 {self.__class__.__name__} initialized with max_retries={max_retries}, agent_name={agent_name}")
logger.info(
"initialized_with_maxretries_agentname",
__name__=self.__class__.__name__,
max_retries=max_retries,
agent_name=agent_name,
)

@abstractmethod
def _build_graph(self) -> Any:
Expand Down
24 changes: 12 additions & 12 deletions src/agents/engine_agent/agent.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,10 +4,10 @@
Focuses on rule descriptions and parameters, using fast validators with LLM reasoning as fallback.
"""

import logging
import time
from typing import Any

import structlog
from langgraph.graph import END, START, StateGraph

from src.agents.base import AgentResult, BaseAgent
Expand All @@ -29,7 +29,7 @@
)
from src.rules.registry import AVAILABLE_CONDITIONS

logger = logging.getLogger(__name__)
logger = structlog.get_logger()


class RuleEngineAgent(BaseAgent):
Expand All @@ -48,9 +48,9 @@ def __init__(self, max_retries: int = 3, timeout: float = 300.0):
super().__init__(max_retries=max_retries, agent_name="engine_agent")
self.timeout = timeout

logger.info("🔧 Rule Engine agent initializing...")
logger.info("rule_engine_agent_initializing")
logger.info(f"🔧 Available validators: {len(AVAILABLE_CONDITIONS)}")
logger.info("🔧 Validation strategy: Hybrid (validators + LLM fallback)")
logger.info("validation_strategy_hybrid_validators_llm_fallback")

def _build_graph(self) -> Any:
"""Build the LangGraph workflow for hybrid rule evaluation."""
Expand Down Expand Up @@ -118,13 +118,13 @@ async def execute(self, **kwargs: Any) -> AgentResult:
llm_usage=0,
)

logger.info("🔧 Rule Engine initial state prepared")
logger.info("rule_engine_initial_state_prepared")

# Run the hybrid graph with timeout
result = await self._execute_with_timeout(self.graph.ainvoke(initial_state), timeout=self.timeout)

execution_time = time.time() - start_time
logger.info(f"🔧 Rule Engine evaluation completed in {execution_time:.2f}s")
logger.info("rule_engine_evaluation_completed", latency_ms=int(execution_time * 1000))

Comment on lines +121 to 128
Copy link

@coderabbitai coderabbitai bot Feb 26, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Potential issue | 🟠 Major

Evaluation boundary logging is missing required decision context.

Line 127 logs latency_ms, but completion context still lacks a canonical operation, subject_ids, and decision payload in the same boundary event. Please emit one final structured completion event with all required fields.

As per coding guidelines: "Use structured logging at boundaries with fields: operation, subject_ids, decision, latency_ms".

Also applies to: 167-170

🤖 Prompt for AI Agents 
Verify each finding against the current code and only fix it if needed.

In `@src/agents/engine_agent/agent.py` around lines 121 - 128, The completion log
after running the hybrid graph (where result = await
self._execute_with_timeout(self.graph.ainvoke(initial_state))) currently only
logs latency_ms; update the final structured logger call (the logger.info near
"rule_engine_evaluation_completed") to include the required fields operation
(e.g., "rule_engine_evaluation_completed"), subject_ids (derived from
initial_state or result), decision (the computed decision from result), and
latency_ms; do the same for the other boundary log near lines 167-170 so both
logger.info calls emit a single structured event containing operation,
subject_ids, decision, and latency_ms, using the existing symbols logger,
_execute_with_timeout, graph.ainvoke, initial_state, and result to populate
fields.

# Extract violations from result
violations = []
Expand All @@ -133,7 +133,7 @@ async def execute(self, **kwargs: Any) -> AgentResult:
elif hasattr(result, "violations"):
violations = result.violations

logger.info(f"🔧 Rule Engine extracted {len(violations)} violations")
logger.info("rule_engine_extracted_violations", num_violations=len(violations))

# Convert violations to RuleViolation objects
rule_violations = []
Expand Down Expand Up @@ -164,9 +164,9 @@ async def execute(self, **kwargs: Any) -> AgentResult:
llm_usage=result.llm_usage if hasattr(result, "llm_usage") else 0,
)

logger.info("🔧 Rule Engine evaluation completed successfully")
logger.info(f"🔧 Validator usage: {evaluation_result.validator_usage}")
logger.info(f"🔧 LLM usage: {evaluation_result.llm_usage} calls")
logger.info("rule_engine_evaluation_completed_successfully")
logger.info("validator_usage", validator_usage=evaluation_result.validator_usage)
logger.info("llm_usage_calls", llm_usage=evaluation_result.llm_usage)

return AgentResult(
success=len(violations) == 0,
Expand All @@ -181,7 +181,7 @@ async def execute(self, **kwargs: Any) -> AgentResult:
)
except Exception as e:
execution_time = time.time() - start_time
logger.error(f"🔧 Error in Rule Engine evaluation: {e}")
logger.error("error_in_rule_engine_evaluation", e=e)
return AgentResult(
success=False,
message=f"Rule Engine evaluation failed: {str(e)}",
Expand Down Expand Up @@ -271,5 +271,5 @@ async def evaluate(

async def evaluate_pull_request(self, rules: list[Any], event_data: dict[str, Any]) -> dict[str, Any]:
"""Legacy method for backwards compatibility."""
logger.warning("evaluate_pull_request is deprecated. Use evaluate() with event_type='pull_request'")
logger.warning("evaluatepullrequest_is_deprecated_use_evaluate_with")
return await self.evaluate("pull_request", rules, event_data, "")
4 changes: 2 additions & 2 deletions src/agents/engine_agent/models.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@

from __future__ import annotations

from enum import Enum
from enum import StrEnum
from typing import Any

from pydantic import BaseModel, ConfigDict, Field
Expand All @@ -24,7 +24,7 @@ class EngineRequest(BaseModel):
model_config = ConfigDict(arbitrary_types_allowed=True)


class ValidationStrategy(str, Enum):
class ValidationStrategy(StrEnum):
"""Validation strategies for rule evaluation."""

VALIDATOR = "validator" # Use fast validator
Expand Down
Loading