diff --git a/src/agents/acknowledgment_agent/agent.py b/src/agents/acknowledgment_agent/agent.py index e3d61cf..35c80be 100644 --- a/src/agents/acknowledgment_agent/agent.py +++ b/src/agents/acknowledgment_agent/agent.py @@ -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 @@ -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): @@ -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: """ @@ -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 @@ -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)) # Validate inputs if not acknowledgment_reason or not violations: @@ -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") @@ -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 = [] @@ -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() @@ -168,11 +166,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() @@ -180,12 +176,12 @@ async def evaluate_acknowledgment( 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, @@ -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()}") @@ -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={} ) diff --git a/src/agents/acknowledgment_agent/test_agent.py b/src/agents/acknowledgment_agent/test_agent.py index 7ddcdbc..81b9936 100644 --- a/src/agents/acknowledgment_agent/test_agent.py +++ b/src/agents/acknowledgment_agent/test_agent.py @@ -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 @@ -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 @@ -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', []))}") @@ -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__": diff --git a/src/agents/base.py b/src/agents/base.py index e6f6a99..b2a7b67 100644 --- a/src/agents/base.py +++ b/src/agents/base.py @@ -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") @@ -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: diff --git a/src/agents/engine_agent/agent.py b/src/agents/engine_agent/agent.py index e85f22a..f8b4fdb 100644 --- a/src/agents/engine_agent/agent.py +++ b/src/agents/engine_agent/agent.py @@ -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 @@ -29,7 +29,7 @@ ) from src.rules.registry import AVAILABLE_CONDITIONS -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class RuleEngineAgent(BaseAgent): @@ -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.""" @@ -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)) # Extract violations from result violations = [] @@ -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 = [] @@ -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, @@ -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)}", @@ -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, "") diff --git a/src/agents/engine_agent/models.py b/src/agents/engine_agent/models.py index a2537d6..3f10fa4 100644 --- a/src/agents/engine_agent/models.py +++ b/src/agents/engine_agent/models.py @@ -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 @@ -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 diff --git a/src/agents/engine_agent/nodes.py b/src/agents/engine_agent/nodes.py index d945c97..04bd654 100644 --- a/src/agents/engine_agent/nodes.py +++ b/src/agents/engine_agent/nodes.py @@ -4,10 +4,10 @@ import asyncio import json -import logging import time from typing import Any, cast +import structlog from langchain_core.messages import HumanMessage, SystemMessage from src.agents.engine_agent.models import ( @@ -24,7 +24,7 @@ ) from src.integrations.providers import get_chat_model -logger = logging.getLogger(__name__) +logger = structlog.get_logger() async def analyze_rule_descriptions(state: EngineState) -> dict[str, Any]: @@ -50,11 +50,11 @@ async def analyze_rule_descriptions(state: EngineState) -> dict[str, Any]: state.rule_descriptions = applicable_rules state.analysis_steps.append(f"Found {len(applicable_rules)} applicable rules out of {len(state.rules)} total") - analysis_time = (time.time() - start_time) * 1000 - logger.info(f"πŸ” Rule analysis completed in {analysis_time:.2f}ms") + elapsed_ms = int((time.time() - start_time) * 1000) + logger.info("rule_analysis_completed", latency_ms=elapsed_ms) except Exception as e: - logger.error(f"❌ Error in rule analysis: {e}") + logger.error("error_in_rule_analysis", error=str(e)) state.analysis_steps.append(f"Error in rule analysis: {str(e)}") return state.model_dump() @@ -87,7 +87,7 @@ async def select_validation_strategy(state: EngineState) -> dict[str, Any]: llm_rules.append(rule_desc) if not llm_rules: - logger.info("🎯 All rules mapped to validators/conditions. Skipping LLM strategy selection.") + logger.info("all_rules_mapped_to_validatorsconditions_skipping") return state.model_dump() logger.info(f"🎯 using LLM to select strategy for {len(llm_rules)} remaining rules") @@ -125,18 +125,18 @@ async def select_validation_strategy(state: EngineState) -> dict[str, Any]: logger.info(f"🎯 Rule '{rule_desc.description[:50]}...' using {rule_desc.validation_strategy} strategy") if rule_desc.validator_name: - logger.info(f"🎯 Selected validator: {rule_desc.validator_name}") + logger.info("selected_validator", validator_name=rule_desc.validator_name) except Exception as e: logger.warning(f"⚠️ LLM strategy selection failed for rule '{rule_desc.description[:50]}...': {e}") rule_desc.validation_strategy = ValidationStrategy.HYBRID rule_desc.validator_name = None - strategy_time = (time.time() - start_time) * 1000 - logger.info(f"🎯 Strategy selection completed in {strategy_time:.2f}ms") + elapsed_ms = int((time.time() - start_time) * 1000) + logger.info("strategy_selection_completed", latency_ms=elapsed_ms) except Exception as e: - logger.error(f"❌ Error in validation strategy selection: {e}") + logger.error("error_in_validation_strategy_selection", error=str(e)) state.analysis_steps.append(f"Error in strategy selection: {str(e)}") return state.model_dump() @@ -155,7 +155,7 @@ async def execute_validator_evaluation(state: EngineState) -> dict[str, Any]: logger.info(f"⚑ Executing {len(validator_rules)} validator evaluations") if not validator_rules: - logger.info("⚑ No validator rules to evaluate") + logger.info("no_validator_rules_to_evaluate") return state.model_dump() # Execute validators concurrently @@ -201,11 +201,11 @@ async def execute_validator_evaluation(state: EngineState) -> dict[str, Any]: if validator_name: state.validator_usage[validator_name] = state.validator_usage.get(validator_name, 0) + 1 - validator_time = (time.time() - start_time) * 1000 - logger.info(f"⚑ Validator evaluation completed in {validator_time:.2f}ms") + elapsed_ms = int((time.time() - start_time) * 1000) + logger.info("validator_evaluation_completed", latency_ms=elapsed_ms) except Exception as e: - logger.error(f"❌ Error in validator evaluation: {e}") + logger.error("error_in_validator_evaluation", error=str(e)) state.analysis_steps.append(f"Error in validator evaluation: {str(e)}") return state.model_dump() @@ -226,7 +226,7 @@ async def execute_llm_fallback(state: EngineState) -> dict[str, Any]: logger.info(f"🧠 Executing {len(llm_rules)} LLM evaluations") if not llm_rules: - logger.info("🧠 No LLM rules to evaluate") + logger.info("no_llm_rules_to_evaluate") return state.model_dump() # Execute LLM evaluations concurrently (with rate limiting) @@ -269,11 +269,11 @@ async def execute_llm_fallback(state: EngineState) -> dict[str, Any]: # Track LLM usage state.llm_usage = len(llm_rules) - llm_time = (time.time() - start_time) * 1000 - logger.info(f"🧠 LLM evaluation completed in {llm_time:.2f}ms") + elapsed_ms = int((time.time() - start_time) * 1000) + logger.info("llm_evaluation_completed", latency_ms=elapsed_ms) except Exception as e: - logger.error(f"❌ Error in LLM evaluation: {e}") + logger.error("error_in_llm_evaluation", error=str(e)) state.analysis_steps.append(f"Error in LLM evaluation: {str(e)}") return state.model_dump() diff --git a/src/agents/factory.py b/src/agents/factory.py index df270a3..0cdb260 100644 --- a/src/agents/factory.py +++ b/src/agents/factory.py @@ -5,16 +5,17 @@ centralizing agent instantiation for consistency. """ -import logging from typing import Any +import structlog + from src.agents.acknowledgment_agent import AcknowledgmentAgent from src.agents.base import BaseAgent from src.agents.engine_agent import RuleEngineAgent from src.agents.feasibility_agent import RuleFeasibilityAgent from src.agents.repository_analysis_agent import RepositoryAnalysisAgent -logger = logging.getLogger(__name__) +logger = structlog.get_logger() def get_agent(agent_type: str, **kwargs: Any) -> BaseAgent: diff --git a/src/agents/feasibility_agent/agent.py b/src/agents/feasibility_agent/agent.py index b3f0f81..b996e3b 100644 --- a/src/agents/feasibility_agent/agent.py +++ b/src/agents/feasibility_agent/agent.py @@ -3,10 +3,10 @@ """ import asyncio -import logging import time from typing import Any +import structlog from langgraph.graph import END, START, StateGraph from langgraph.graph.state import CompiledStateGraph @@ -14,7 +14,7 @@ from src.agents.feasibility_agent.models import FeasibilityState from src.agents.feasibility_agent.nodes import analyze_rule_feasibility, generate_yaml_config -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class RuleFeasibilityAgent(BaseAgent): @@ -31,7 +31,7 @@ class RuleFeasibilityAgent(BaseAgent): def __init__(self, max_retries: int = 3, timeout: float = 30.0): super().__init__(max_retries=max_retries, agent_name="feasibility_agent") self.timeout = timeout - logger.info(f"πŸ”§ FeasibilityAgent initialized with max_retries={max_retries}, timeout={timeout}s") + logger.info("feasibilityagent_initialized_with_maxretries_timeout_s", max_retries=max_retries, timeout=timeout) def _build_graph(self) -> CompiledStateGraph: """Build the LangGraph workflow for rule feasibility checking.""" @@ -53,7 +53,7 @@ def _build_graph(self) -> CompiledStateGraph: workflow.add_edge("generate_yaml", END) - logger.info("πŸ”§ FeasibilityAgent graph built with conditional structured output workflow") + logger.info("feasibilityagent_graph_built_with_conditional_structured") return workflow.compile() async def execute(self, **kwargs: Any) -> AgentResult: @@ -80,9 +80,12 @@ async def execute(self, **kwargs: Any) -> AgentResult: result = FeasibilityState(**result) execution_time = time.time() - start_time - logger.info(f"βœ… Feasibility analysis completed in {execution_time:.2f}s") + logger.info("feasibility_analysis_completed_in_s") logger.info( - f"βœ… Results: feasible={result.is_feasible}, type={result.rule_type}, confidence={result.confidence_score}" + "results_feasible_type_confidence", + is_feasible=result.is_feasible, + rule_type=result.rule_type, + confidence_score=result.confidence_score, ) # Convert to AgentResult with metadata @@ -106,7 +109,7 @@ async def execute(self, **kwargs: Any) -> AgentResult: except TimeoutError: execution_time = time.time() - start_time - logger.error(f"❌ Feasibility analysis timed out after {execution_time:.2f}s") + logger.error("feasibility_analysis_timed_out_after_s") return AgentResult( success=False, message=f"Feasibility analysis timed out after {self.timeout}s", @@ -120,7 +123,7 @@ async def execute(self, **kwargs: Any) -> AgentResult: except Exception as e: execution_time = time.time() - start_time - logger.error(f"❌ Feasibility analysis failed: {e}") + logger.error("feasibility_analysis_failed", e=e) return AgentResult( success=False, message=f"Feasibility analysis failed: {str(e)}", @@ -140,7 +143,7 @@ async def execute_with_retry(self, rule_description: str) -> AgentResult: result.metadata["retry_count"] = attempt return result else: - logger.warning(f"⚠️ Feasibility analysis failed on attempt {attempt + 1}") + logger.warning("feasibility_analysis_failed_on_attempt") if attempt == self.max_retries - 1: return result @@ -148,7 +151,7 @@ async def execute_with_retry(self, rule_description: str) -> AgentResult: await asyncio.sleep(self.retry_delay * (2**attempt)) except Exception as e: - logger.error(f"❌ Exception on attempt {attempt + 1}: {e}") + logger.error("exception_on_attempt", e=e) if attempt == self.max_retries - 1: return AgentResult( success=False, diff --git a/src/agents/feasibility_agent/nodes.py b/src/agents/feasibility_agent/nodes.py index 7634c5b..d4768a3 100644 --- a/src/agents/feasibility_agent/nodes.py +++ b/src/agents/feasibility_agent/nodes.py @@ -2,14 +2,14 @@ LangGraph nodes for the Rule Feasibility Agent with enhanced error handling. """ -import logging +import structlog from src.agents.feasibility_agent.models import FeasibilityAnalysis, FeasibilityState, YamlGeneration from src.agents.feasibility_agent.prompts import RULE_FEASIBILITY_PROMPT, YAML_GENERATION_PROMPT from src.integrations.providers import get_chat_model from src.rules.registry import AVAILABLE_CONDITIONS -logger = logging.getLogger(__name__) +logger = structlog.get_logger() async def analyze_rule_feasibility(state: FeasibilityState) -> FeasibilityState: @@ -55,13 +55,13 @@ async def analyze_rule_feasibility(state: FeasibilityState) -> FeasibilityState: state.feedback = result.feedback state.analysis_steps = result.analysis_steps - logger.info(f"πŸ” Rule feasibility analysis completed: {state.is_feasible}") - logger.info(f"πŸ” Rule type identified: {state.rule_type}") - logger.info(f"πŸ” Confidence score: {state.confidence_score}") + logger.info("rule_feasibility_analysis_completed", is_feasible=state.is_feasible) + logger.info("rule_type_identified", rule_type=state.rule_type) + logger.info("confidence_score", confidence_score=state.confidence_score) logger.info(f"πŸ” Analysis steps: {len(state.analysis_steps)} steps") except Exception as e: - logger.error(f"❌ Error in rule feasibility analysis: {e}") + logger.error("error_in_rule_feasibility_analysis", e=e) state.is_feasible = False state.feedback = f"Analysis failed: {str(e)}" state.confidence_score = 0.0 @@ -76,7 +76,7 @@ async def generate_yaml_config(state: FeasibilityState) -> FeasibilityState: This node only runs if the rule is feasible. """ if not state.is_feasible or not state.rule_type: - logger.info("πŸ”§ Skipping YAML generation - rule not feasible or no rule type") + logger.info("skipping_yaml_generation_rule_not_feasible") return state try: @@ -119,14 +119,14 @@ async def generate_yaml_config(state: FeasibilityState) -> FeasibilityState: # Basic validation of generated YAML if not state.yaml_content or len(state.yaml_content) < 10: - logger.warning("⚠️ Generated YAML seems too short, may be invalid") + logger.warning("generated_yaml_seems_too_short_may") state.feedback += "\nWarning: Generated YAML may be incomplete" - logger.info(f"πŸ”§ YAML configuration generated for rule type: {state.rule_type}") + logger.info("yaml_configuration_generated_for_rule_type", rule_type=state.rule_type) logger.info(f"πŸ”§ Generated YAML length: {len(state.yaml_content)} characters") except Exception as e: - logger.error(f"❌ Error generating YAML configuration: {e}") + logger.error("error_generating_yaml_configuration", e=e) state.feedback += f"\nYAML generation failed: {str(e)}" state.yaml_content = "" diff --git a/src/api/dependencies.py b/src/api/dependencies.py index f5d99f8..9ba6583 100644 --- a/src/api/dependencies.py +++ b/src/api/dependencies.py @@ -1,11 +1,10 @@ -import logging - +import structlog from fastapi import Depends, HTTPException, Request, status from src.core.models import User from src.integrations.github.service import GitHubService -logger = logging.getLogger(__name__) # Logger: keep at module level for reuse. +logger = structlog.get_logger() # Logger: keep at module level for reuse. # --- Service Dependencies --- # DI: swap for mock in tests. @@ -47,11 +46,14 @@ async def get_current_user_optional(request: Request) -> User | None: # In real usage, we would validate the token here or pass it to endpoints to use against GitHub API # For now, we return a User object wrapping the token so it can be used by services # We use a dummy ID for the anonymous/token-holder user logic - logger.debug("Creating user wrapper for provided token") + logger.debug("creating_user_wrapper_for_provided_token") return User(id=0, username="token_user", email="token@user.com", github_token=SecretStr(token)) - except Exception as e: - logger.warning(f"Failed to parse auth header: {e}") + except ValueError as e: + logger.warning("failed_to_parse_auth_header", error=str(e)) return None + except Exception: + logger.exception("unexpected_auth_header_parse_failure") + raise async def get_current_user(user: User | None = Depends(get_current_user_optional)) -> User: diff --git a/src/core/models.py b/src/core/models.py index c5eeef4..b72eb4f 100644 --- a/src/core/models.py +++ b/src/core/models.py @@ -1,5 +1,5 @@ from datetime import UTC, datetime -from enum import Enum, StrEnum +from enum import StrEnum from typing import Any, Literal from pydantic import BaseModel, Field, SecretStr, field_validator @@ -88,7 +88,7 @@ class RuleConfig(BaseModel): parameters: dict[str, Any] = Field(default_factory=dict, description="Rule parameters for validators") -class EventType(str, Enum): +class EventType(StrEnum): """ Supported GitHub Event Types. Reference: project_detail_med.md [cite: 32] diff --git a/src/core/utils/caching.py b/src/core/utils/caching.py index 24fa39b..461da5f 100644 --- a/src/core/utils/caching.py +++ b/src/core/utils/caching.py @@ -5,15 +5,15 @@ for caching function results. """ -import logging from collections.abc import Callable from datetime import datetime from functools import wraps from typing import Any +import structlog from cachetools import TTLCache # type: ignore -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class AsyncCache: @@ -62,7 +62,7 @@ def get(self, key: str) -> Any | None: logger.debug(f"Cache entry '{key}' expired (age: {age:.2f}s, ttl: {self.ttl}s)") return None - logger.debug(f"Cache hit for '{key}'") + logger.debug("cache_hit_for", key=key) return cached_data.get("value") def set(self, key: str, value: Any) -> None: @@ -79,20 +79,20 @@ def set(self, key: str, value: Any) -> None: self._cache.keys(), key=lambda k: self._cache[k].get("timestamp", 0), ) - logger.debug(f"Cache full, evicting oldest entry '{oldest_key}'") + logger.debug("cache_full_evicting_oldest_entry", oldest_key=oldest_key) del self._cache[oldest_key] self._cache[key] = { "value": value, "timestamp": datetime.now().timestamp(), } - logger.debug(f"Cached entry '{key}'") + logger.debug("cached_entry", key=key) def clear(self) -> None: """Clear all cached values.""" count = len(self._cache) self._cache.clear() - logger.debug(f"Cleared {count} cache entries") + logger.debug("cleared_cache_entries", count=count) def invalidate(self, key: str) -> None: """ @@ -103,7 +103,7 @@ def invalidate(self, key: str) -> None: """ if key in self._cache: del self._cache[key] - logger.debug(f"Invalidated cache entry '{key}'") + logger.debug("invalidated_cache_entry", key=key) def size(self) -> int: """ @@ -175,11 +175,11 @@ async def wrapper(*args: Any, **kwargs: Any) -> Any: cached_value = cache.get(cache_key) if cached_value is not None: - logger.debug(f"Cache hit for {func.__name__} with key '{cache_key}'") + logger.debug("cache_hit_for_with_key", __name__=func.__name__, cache_key=cache_key) return cached_value # Cache miss - execute function - logger.debug(f"Cache miss for {func.__name__} with key '{cache_key}'") + logger.debug("cache_miss_for_with_key", __name__=func.__name__, cache_key=cache_key) result = await func(*args, **kwargs) # Store in cache diff --git a/src/core/utils/logging.py b/src/core/utils/logging.py index f45923e..80479b6 100644 --- a/src/core/utils/logging.py +++ b/src/core/utils/logging.py @@ -8,14 +8,18 @@ from __future__ import annotations import inspect -import logging import time -from collections.abc import Callable # noqa: TCH003 +from collections.abc import AsyncIterator, Callable # noqa: TCH003 from contextlib import asynccontextmanager from functools import wraps -from typing import Any +from typing import TYPE_CHECKING, Any -logger = logging.getLogger(__name__) +import structlog + +if TYPE_CHECKING: + import logging + +logger = structlog.get_logger() @asynccontextmanager @@ -23,7 +27,7 @@ async def log_operation( operation: str, subject_ids: dict[str, str] | None = None, **context: Any, -) -> Any: # AsyncGenerator[None, None] +) -> AsyncIterator[None]: """ Context manager for structured operation logging. @@ -87,12 +91,12 @@ def decorator(func: Callable[..., Any]) -> Callable[..., Any]: @wraps(func) async def async_wrapper(*args: Any, **kwargs: Any) -> Any: start_time = time.time() - logger.info(f"πŸš€ Calling {op_name}") + logger.info("calling", op_name=op_name) try: result = await func(*args, **kwargs) latency_ms = int((time.time() - start_time) * 1000) - logger.info(f"βœ… {op_name} completed in {latency_ms}ms") + logger.info("completed_in_ms", op_name=op_name, latency_ms=latency_ms) return result except Exception as e: latency_ms = int((time.time() - start_time) * 1000) @@ -105,12 +109,12 @@ async def async_wrapper(*args: Any, **kwargs: Any) -> Any: @wraps(func) def sync_wrapper(*args: Any, **kwargs: Any) -> Any: start_time = time.time() - logger.info(f"πŸš€ Calling {op_name}") + logger.info("calling", op_name=op_name) try: result = func(*args, **kwargs) latency_ms = int((time.time() - start_time) * 1000) - logger.info(f"βœ… {op_name} completed in {latency_ms}ms") + logger.info("completed_in_ms", op_name=op_name, latency_ms=latency_ms) return result except Exception as e: latency_ms = int((time.time() - start_time) * 1000) diff --git a/src/core/utils/metrics.py b/src/core/utils/metrics.py index b322905..992825b 100644 --- a/src/core/utils/metrics.py +++ b/src/core/utils/metrics.py @@ -5,13 +5,14 @@ for operations, API calls, and agent executions. """ -import logging import time from contextlib import asynccontextmanager from functools import wraps from typing import Any -logger = logging.getLogger(__name__) +import structlog + +logger = structlog.get_logger() @asynccontextmanager diff --git a/src/core/utils/retry.py b/src/core/utils/retry.py index 20d6a2e..7b61d25 100644 --- a/src/core/utils/retry.py +++ b/src/core/utils/retry.py @@ -6,12 +6,13 @@ """ import asyncio -import logging from collections.abc import Awaitable, Callable from functools import wraps from typing import Any, TypeVar -logger = logging.getLogger(__name__) +import structlog + +logger = structlog.get_logger() T = TypeVar("T") @@ -52,12 +53,12 @@ async def wrapper(*args: Any, **kwargs: Any) -> Any: try: result = await func(*args, **kwargs) if attempt > 0: - logger.info(f"βœ… {func.__name__} succeeded on attempt {attempt + 1}/{max_retries}") + logger.info("succeeded_on_attempt", __name__=func.__name__, max_retries=max_retries) return result except exceptions as e: last_exception = e if attempt == max_retries - 1: - logger.error(f"❌ {func.__name__} failed after {max_retries} attempts: {e}") + logger.error("failed_after_attempts", __name__=func.__name__, max_retries=max_retries, e=e) raise wait_time = min(delay, max_delay) @@ -119,13 +120,11 @@ async def retry_async[T]( except exceptions as e: last_exception = e if attempt == max_retries - 1: - logger.error(f"❌ {func.__name__} failed after {max_retries} attempts: {e}") + logger.error("failed_after_attempts", __name__=func.__name__, max_retries=max_retries, e=e) raise wait_time = min(delay, max_delay) - logger.warning( - f"⚠️ {func.__name__} attempt {attempt + 1}/{max_retries} failed, retrying in {wait_time:.2f}s: {e}" - ) + logger.warning("attempt_failed_retrying_in_s", __name__=func.__name__, max_retries=max_retries, e=e) await asyncio.sleep(wait_time) delay *= exponential_base diff --git a/src/core/utils/timeout.py b/src/core/utils/timeout.py index 93d6f15..424a7d1 100644 --- a/src/core/utils/timeout.py +++ b/src/core/utils/timeout.py @@ -5,11 +5,12 @@ """ import asyncio -import logging from collections.abc import Coroutine from typing import Any -logger = logging.getLogger(__name__) +import structlog + +logger = structlog.get_logger() async def execute_with_timeout( @@ -41,7 +42,7 @@ async def execute_with_timeout( return await asyncio.wait_for(coro, timeout=timeout) except TimeoutError as err: msg = timeout_message or f"Operation timed out after {timeout} seconds" - logger.error(f"❌ {msg}") + logger.error("event", msg=msg) raise TimeoutError(msg) from err diff --git a/src/event_processors/base.py b/src/event_processors/base.py index 5cac2d0..a282007 100644 --- a/src/event_processors/base.py +++ b/src/event_processors/base.py @@ -1,7 +1,7 @@ -import logging from abc import ABC, abstractmethod from typing import Any +import structlog from pydantic import BaseModel, Field from src.core.models import Violation, WebhookEvent @@ -10,7 +10,7 @@ from src.rules.loaders.github_loader import GitHubRuleLoader from src.tasks.task_queue import Task -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class ProcessingResult(BaseModel): diff --git a/src/event_processors/check_run.py b/src/event_processors/check_run.py index 1a73eed..e218738 100644 --- a/src/event_processors/check_run.py +++ b/src/event_processors/check_run.py @@ -1,12 +1,13 @@ -import logging import time from typing import Any +import structlog + from src.agents import get_agent from src.event_processors.base import BaseEventProcessor, ProcessingResult from src.tasks.task_queue import Task -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class CheckRunProcessor(BaseEventProcessor): @@ -29,13 +30,13 @@ async def process(self, task: Task) -> ProcessingResult: # Ignore our own check runs to prevent infinite loops if "watchflow" in check_run.get("name", "").lower(): - logger.info("Ignoring Watchflow's own check run to prevent recursive loops.") + logger.info("ignoring_watchflows_own_check_run_to") return ProcessingResult( success=True, violations=[], api_calls_made=0, processing_time_ms=int((time.time() - start_time) * 1000) ) logger.info("=" * 80) - logger.info(f"πŸš€ Processing CHECK RUN event for {task.repo_full_name}") + logger.info("processing_check_run_event_for", repo_full_name=task.repo_full_name) logger.info(f" Name: {check_run.get('name')}") logger.info(f" Status: {check_run.get('status')}") logger.info(f" Conclusion: {check_run.get('conclusion')}") @@ -53,7 +54,7 @@ async def process(self, task: Task) -> ProcessingResult: # Fetch rules if not task.installation_id: - logger.error("No installation ID found in task") + logger.error("no_installation_id_found_in_task") return ProcessingResult( success=False, violations=[], diff --git a/src/event_processors/deployment.py b/src/event_processors/deployment.py index 6160fc7..e10a88b 100644 --- a/src/event_processors/deployment.py +++ b/src/event_processors/deployment.py @@ -1,11 +1,12 @@ -import logging import time from typing import Any +import structlog + from src.event_processors.base import BaseEventProcessor, ProcessingResult from src.tasks.task_queue import Task -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class DeploymentProcessor(BaseEventProcessor): @@ -29,16 +30,26 @@ async def process(self, task: Task) -> ProcessingResult: deployment_id = deployment.get("id") logger.info("=" * 80) - logger.info(f"πŸš€ Processing DEPLOYMENT event for {task.repo_full_name}") - logger.info(f" Environment: {environment}") - logger.info(f" Creator: {creator}") - logger.info(f" Ref: {ref}") - logger.info(f" Deployment ID: {deployment_id}") + logger.info( + "deployment_processing_started", + operation="process_deployment", + subject_ids={"repo_full_name": task.repo_full_name, "deployment_id": deployment_id}, + decision="accepted", + environment=environment, + creator=creator, + ref=ref, + ) logger.info("=" * 80) # Just log the deployment creation - no rule evaluation here # Rule evaluation will be handled by deployment_protection_rule events - logger.info(f"πŸ“‹ Deployment {deployment_id} created for {environment}") + logger.info( + "deployment_created", + operation="process_deployment", + subject_ids={"repo_full_name": task.repo_full_name, "deployment_id": deployment_id}, + decision="created", + environment=environment, + ) logger.info("=" * 80) logger.info(f"🏁 DEPLOYMENT processing completed in {int((time.time() - start_time) * 1000)}ms") logger.info("=" * 80) diff --git a/src/event_processors/deployment_protection_rule.py b/src/event_processors/deployment_protection_rule.py index 7b5f3fd..52c5919 100644 --- a/src/event_processors/deployment_protection_rule.py +++ b/src/event_processors/deployment_protection_rule.py @@ -1,7 +1,8 @@ -import logging import time from typing import Any +import structlog + from src.agents import get_agent from src.core.utils.retry import retry_async from src.core.utils.timeout import execute_with_timeout @@ -9,7 +10,7 @@ from src.tasks.scheduler.deployment_scheduler import get_deployment_scheduler from src.tasks.task_queue import Task -logger = logging.getLogger(__name__) +logger = structlog.get_logger() AGENT_TIMEOUT_SECONDS = 30.0 @@ -75,7 +76,7 @@ async def process(self, task: Task) -> ProcessingResult: rules = await self.rule_provider.get_rules(repo_full_name, installation_id) if not rules: - logger.info("No rules found for repository") + logger.info("no_rules_found_for_repository") if can_call_callback: approved = await self._approve_deployment( deployment_callback_url, environment, "No rules configured", installation_id @@ -109,7 +110,7 @@ async def process(self, task: Task) -> ProcessingResult: deployment_rules.append(r) if not deployment_rules: - logger.info("No deployment rules found") + logger.info("no_deployment_rules_found") if can_call_callback: approved = await self._approve_deployment( deployment_callback_url, @@ -182,7 +183,7 @@ async def process(self, task: Task) -> ProcessingResult: processing_time_ms=int((time.time() - start_time) * 1000), error="Approval API failed after retries", ) - logger.info("All rules passed, deployment approved") + logger.info("all_rules_passed_deployment_approved") else: time_based_violations = self._check_time_based_violations(violations) if time_based_violations and can_call_callback: @@ -200,7 +201,7 @@ async def process(self, task: Task) -> ProcessingResult: "callback_url": deployment_callback_url, } ) - logger.info("Time-based violations detected, added to scheduler for re-evaluation") + logger.info("timebased_violations_detected_added_to_scheduler") if can_call_callback: rejected = await self._reject_deployment( diff --git a/src/event_processors/deployment_review.py b/src/event_processors/deployment_review.py index b06af07..b795eaf 100644 --- a/src/event_processors/deployment_review.py +++ b/src/event_processors/deployment_review.py @@ -1,12 +1,13 @@ -import logging import time from typing import Any +import structlog + from src.agents import get_agent from src.event_processors.base import BaseEventProcessor, ProcessingResult from src.tasks.task_queue import Task -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class DeploymentReviewProcessor(BaseEventProcessor): @@ -28,7 +29,7 @@ async def process(self, task: Task) -> ProcessingResult: deployment_review = payload.get("deployment_review", {}) logger.info("=" * 80) - logger.info(f"πŸš€ Processing DEPLOYMENT REVIEW event for {task.repo_full_name}") + logger.info("processing_deployment_review_event_for", repo_full_name=task.repo_full_name) logger.info(f" State: {deployment_review.get('state')}") logger.info(f" Environment: {deployment_review.get('environment')}") logger.info("=" * 80) @@ -59,7 +60,7 @@ async def process(self, task: Task) -> ProcessingResult: # Fetch rules if not task.installation_id: - logger.error("No installation ID found in task") + logger.error("no_installation_id_found_in_task") return ProcessingResult( success=False, violations=[], @@ -88,7 +89,7 @@ async def process(self, task: Task) -> ProcessingResult: deployment_review_rules.append(r) if not deployment_review_rules: - logger.info("πŸ“‹ No deployment_review rules found") + logger.info("no_deploymentreview_rules_found") return ProcessingResult( success=True, violations=[], api_calls_made=1, processing_time_ms=int((time.time() - start_time) * 1000) ) diff --git a/src/event_processors/deployment_status.py b/src/event_processors/deployment_status.py index 5a55c60..72cf615 100644 --- a/src/event_processors/deployment_status.py +++ b/src/event_processors/deployment_status.py @@ -1,11 +1,12 @@ -import logging import time from typing import Any +import structlog + from src.event_processors.base import BaseEventProcessor, ProcessingResult from src.tasks.task_queue import Task -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class DeploymentStatusProcessor(BaseEventProcessor): @@ -29,23 +30,23 @@ async def process(self, task: Task) -> ProcessingResult: creator = deployment.get("creator", {}).get("login", "") logger.info("=" * 80) - logger.info(f"πŸ“Š Processing DEPLOYMENT_STATUS event for {task.repo_full_name}") - logger.info(f" State: {state}") - logger.info(f" Environment: {environment}") - logger.info(f" Creator: {creator}") + logger.info("processing_deploymentstatus_event_for", repo_full_name=task.repo_full_name) + logger.info("state", state=state) + logger.info("environment", environment=environment) + logger.info("creator", creator=creator) logger.info("=" * 80) # Log different states for monitoring purposes if state == "error": - logger.info(f"πŸ’₯ Deployment to {environment} had an error") + logger.info("deployment_to_had_an_error", environment=environment) elif state == "waiting": - logger.info(f"⏳ Deployment to {environment} is waiting for protection rule review") + logger.info("deployment_to_is_waiting_for_protection", environment=environment) elif state == "success": - logger.info(f"βœ… Deployment to {environment} was successful") + logger.info("deployment_to_was_successful", environment=environment) elif state == "failure": - logger.info(f"❌ Deployment to {environment} failed") + logger.info("deployment_to_failed", environment=environment) else: - logger.info(f"πŸ“‹ Deployment to {environment} has state: {state}") + logger.info("deployment_to_has_state", environment=environment, state=state) logger.info("=" * 80) logger.info(f"🏁 DEPLOYMENT_STATUS processing completed in {int((time.time() - start_time) * 1000)}ms") diff --git a/src/event_processors/pull_request/enricher.py b/src/event_processors/pull_request/enricher.py index 70c0193..af30271 100644 --- a/src/event_processors/pull_request/enricher.py +++ b/src/event_processors/pull_request/enricher.py @@ -1,13 +1,14 @@ -import logging from typing import Any +import structlog + from src.core.models import Acknowledgment from src.rules.acknowledgment import ( is_acknowledgment_comment, parse_acknowledgment_comment, ) -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class PullRequestEnricher: @@ -32,7 +33,7 @@ async def fetch_api_data(self, repo_full_name: str, pr_number: int, installation api_data["files"] = files or [] except Exception as e: - logger.error(f"Error fetching API data for PR #{pr_number}: {e}") + logger.error("error_fetching_api_data_for_pr", pr_number=pr_number, e=e) return api_data @@ -109,7 +110,7 @@ async def fetch_acknowledgments(self, repo: str, pr_number: int, installation_id return acknowledgments except Exception as e: - logger.error(f"Error fetching acknowledgments: {e}") + logger.error("error_fetching_acknowledgments", e=e) return {} def prepare_webhook_data(self, task: Any) -> dict[str, Any]: diff --git a/src/event_processors/pull_request/processor.py b/src/event_processors/pull_request/processor.py index 501180f..f18e55f 100644 --- a/src/event_processors/pull_request/processor.py +++ b/src/event_processors/pull_request/processor.py @@ -1,7 +1,8 @@ -import logging import time from typing import Any +import structlog + from src.agents import get_agent from src.core.models import Violation from src.event_processors.base import BaseEventProcessor, ProcessingResult @@ -11,7 +12,7 @@ from src.rules.loaders.github_loader import RulesFileNotFoundError from src.tasks.task_queue import Task -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class PullRequestProcessor(BaseEventProcessor): @@ -39,7 +40,7 @@ async def process(self, task: Task) -> ProcessingResult: sha = pr_data.get("head", {}).get("sha") if not installation_id: - logger.error("No installation ID found in task") + logger.error("no_installation_id_found_in_task") return ProcessingResult( success=False, violations=[], @@ -64,9 +65,9 @@ async def process(self, task: Task) -> ProcessingResult: try: logger.info("=" * 80) - logger.info(f"πŸš€ Processing PR event for {repo_full_name}") + logger.info("processing_pr_event_for", repo_full_name=repo_full_name) logger.info(f" Action: {task.payload.get('action')}") - logger.info(f" PR Number: {pr_number}") + logger.info("pr_number", pr_number=pr_number) logger.info("=" * 80) github_token_optional = await self.github_client.get_installation_access_token(installation_id) @@ -84,7 +85,7 @@ async def process(self, task: Task) -> ProcessingResult: rules = rules_optional if rules_optional is not None else [] api_calls += 1 except RulesFileNotFoundError as e: - logger.warning(f"Rules file not found: {e}") + logger.warning("rules_file_not_found", e=e) if sha: await self.check_run_manager.create_check_run( repo=repo_full_name, @@ -105,7 +106,7 @@ async def process(self, task: Task) -> ProcessingResult: repo_full_name, pr_number, welcome_comment, installation_id ) except Exception as comment_err: - logger.warning(f"Could not post rules-not-configured comment: {comment_err}") + logger.warning("could_not_post_rulesnotconfigured_comment", comment_err=comment_err) return ProcessingResult( success=True, violations=[], @@ -178,7 +179,7 @@ async def process(self, task: Task) -> ProcessingResult: processing_time = int((time.time() - start_time) * 1000) logger.info("=" * 80) - logger.info(f"🏁 PR processing completed in {processing_time}ms") + logger.info("pr_processing_completed_in_ms", processing_time=processing_time) logger.info("=" * 80) return ProcessingResult( @@ -189,7 +190,7 @@ async def process(self, task: Task) -> ProcessingResult: ) except Exception as e: - logger.error(f"❌ Error processing PR event: {e}") + logger.error("error_processing_pr_event", e=e) if sha: await self.check_run_manager.create_check_run( repo=repo_full_name, @@ -219,7 +220,7 @@ async def _post_violations_to_github(self, task: Task, violations: list[Violatio task.repo_full_name, pr_number, comment_body, task.installation_id ) except Exception as e: - logger.error(f"Error posting violations to GitHub: {e}") + logger.error("error_posting_violations_to_github", e=e) async def prepare_webhook_data(self, task: Task) -> dict[str, Any]: """Extract data available in webhook payload.""" diff --git a/src/event_processors/push.py b/src/event_processors/push.py index a720741..278d328 100644 --- a/src/event_processors/push.py +++ b/src/event_processors/push.py @@ -1,7 +1,8 @@ -import logging import time from typing import Any +import structlog + from src.agents import get_agent from src.core.models import Severity, Violation from src.core.utils.event_filter import NULL_SHA @@ -9,7 +10,7 @@ from src.integrations.github.check_runs import CheckRunManager from src.tasks.task_queue import Task -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class PushProcessor(BaseEventProcessor): @@ -33,13 +34,13 @@ async def process(self, task: Task) -> ProcessingResult: commits = payload.get("commits", []) logger.info("=" * 80) - logger.info(f"πŸš€ Processing PUSH event for {task.repo_full_name}") - logger.info(f" Ref: {ref}") + logger.info("processing_push_event_for", repo_full_name=task.repo_full_name) + logger.info("ref", ref=ref) logger.info(f" Commits: {len(commits)}") logger.info("=" * 80) if payload.get("deleted") or not payload.get("after") or payload.get("after") == NULL_SHA: - logger.info("push_skipped_deleted_or_empty") + logger.info("pushskippeddeletedorempty") return ProcessingResult( success=True, violations=[], @@ -63,7 +64,7 @@ async def process(self, task: Task) -> ProcessingResult: } if not task.installation_id: - logger.error("No installation ID found in task") + logger.error("no_installation_id_found_in_task") return ProcessingResult( success=False, violations=[], @@ -76,7 +77,7 @@ async def process(self, task: Task) -> ProcessingResult: rules = rules_optional if rules_optional is not None else [] if not rules: - logger.info("No rules found for this repository") + logger.info("no_rules_found_for_this_repository") return ProcessingResult( success=True, violations=[], api_calls_made=1, processing_time_ms=int((time.time() - start_time) * 1000) ) @@ -109,7 +110,7 @@ async def process(self, task: Task) -> ProcessingResult: ) violations.append(violation) except Exception as e: - logger.error(f"Error converting violation: {e}") + logger.error("error_converting_violation", e=e) processing_time = int((time.time() - start_time) * 1000) @@ -117,11 +118,11 @@ async def process(self, task: Task) -> ProcessingResult: sha = payload.get("after") if not sha or sha == "0000000000000000000000000000000000000000": - logger.warning("No valid commit SHA found, skipping check run") + logger.warning("no_valid_commit_sha_found_skipping") else: # Ensure installation_id is not None before passing to check_run_manager if task.installation_id is None: - logger.warning("Missing installation_id for push event, cannot create check run") + logger.warning("missing_installationid_for_push_event_cannot") else: if violations: await self.check_run_manager.create_check_run( @@ -144,10 +145,10 @@ async def process(self, task: Task) -> ProcessingResult: logger.info("=" * 80) - logger.info(f"🏁 PUSH processing completed in {processing_time}ms") + logger.info("push_processing_completed_in_ms", processing_time=processing_time) logger.info(f" Rules evaluated: {len(formatted_rules)}") logger.info(f" Violations found: {len(violations)}") - logger.info(f" API calls made: {api_calls}") + logger.info("api_calls_made", api_calls=api_calls) logger.info("=" * 80) return ProcessingResult( diff --git a/src/event_processors/rule_creation.py b/src/event_processors/rule_creation.py index 036087d..425ebac 100644 --- a/src/event_processors/rule_creation.py +++ b/src/event_processors/rule_creation.py @@ -1,14 +1,15 @@ -import logging import re import time from typing import Any +import structlog + from src.agents import get_agent from src.agents.base import AgentResult from src.event_processors.base import BaseEventProcessor, ProcessingResult from src.tasks.task_queue import Task -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class RuleCreationProcessor(BaseEventProcessor): @@ -30,7 +31,7 @@ async def process(self, task: Task) -> ProcessingResult: try: logger.info("=" * 80) - logger.info(f"πŸš€ Processing RULE CREATION command for {task.repo_full_name}") + logger.info("processing_rule_creation_command_for", repo_full_name=task.repo_full_name) logger.info("=" * 80) # Extract the rule description from the comment @@ -45,7 +46,7 @@ async def process(self, task: Task) -> ProcessingResult: error="No rule description found in comment", ) - logger.info(f"πŸ“ Rule description: {rule_description}") + logger.info("rule_description", rule_description=rule_description) # Use the feasibility agent to check if the rule is supported feasibility_result = await self.feasibility_agent.execute(rule_description=rule_description) @@ -57,21 +58,21 @@ async def process(self, task: Task) -> ProcessingResult: # Summary logger.info("=" * 80) - logger.info(f"🏁 Rule creation processing completed in {processing_time}ms") - logger.info(f" Feasible: {feasibility_result.success}") - logger.info(" API calls made: 1") + logger.info("rule_creation_processing_completed_in_ms", processing_time=processing_time) + logger.info("feasible", success=feasibility_result.success) + logger.info("api_calls_made_1") if feasibility_result.success: - logger.info("βœ… Rule is feasible - YAML provided") + logger.info("rule_is_feasible_yaml_provided") else: - logger.info("❌ Rule is not feasible - feedback provided") + logger.info("rule_is_not_feasible_feedback_provided") logger.info("=" * 80) return ProcessingResult(success=True, violations=[], api_calls_made=1, processing_time_ms=processing_time) except Exception as e: - logger.error(f"❌ Error processing rule creation: {e}") + logger.error("error_processing_rule_creation", e=e) return ProcessingResult( success=False, violations=[], @@ -106,7 +107,7 @@ async def _post_result_to_comment(self, task: Task, feasibility_result: AgentRes issue_number = issue.get("number") if not issue_number or not task.installation_id: - logger.warning("No issue number or installation_id found in webhook payload, skipping reply") + logger.warning("no_issue_number_or_installationid_found") return reply_body = self._format_feasibility_reply(feasibility_result) @@ -117,12 +118,12 @@ async def _post_result_to_comment(self, task: Task, feasibility_result: AgentRes ) if result: - logger.info(f"βœ… Successfully posted feasibility reply to issue/PR #{issue_number}") + logger.info("successfully_posted_feasibility_reply_to_issuepr", issue_number=issue_number) else: - logger.error(f"❌ Failed to post feasibility reply to issue/PR #{issue_number}") + logger.error("failed_to_post_feasibility_reply_to", issue_number=issue_number) except Exception as e: - logger.error(f"Error posting feasibility reply: {e}") + logger.error("error_posting_feasibility_reply", e=e) def _format_feasibility_reply(self, feasibility_result: AgentResult) -> str: """Format the feasibility result as a comment reply.""" diff --git a/src/event_processors/violation_acknowledgment.py b/src/event_processors/violation_acknowledgment.py index 77e50f7..ddb24eb 100644 --- a/src/event_processors/violation_acknowledgment.py +++ b/src/event_processors/violation_acknowledgment.py @@ -1,7 +1,8 @@ -import logging import time from typing import TYPE_CHECKING, Any +import structlog + from src.agents import get_agent from src.core.models import Acknowledgment, EventType, Violation from src.event_processors.base import BaseEventProcessor, ProcessingResult @@ -12,7 +13,7 @@ if TYPE_CHECKING: from src.agents.acknowledgment_agent.agent import AcknowledgmentAgent -logger = logging.getLogger(__name__) +logger = structlog.get_logger() # Add at the top acknowledged_prs: set[str] = set() @@ -57,8 +58,8 @@ async def process(self, task: Task) -> ProcessingResult: sha = "" logger.info("=" * 80) - logger.info(f"πŸ” Processing VIOLATION ACKNOWLEDGMENT for {repo}#{pr_number}") - logger.info(f" Commenter: {commenter}") + logger.info("processing_violation_acknowledgment_for", repo=repo, pr_number=pr_number) + logger.info("commenter", commenter=commenter) logger.info(f" Comment: {comment_body[:100]}...") logger.info("=" * 80) @@ -66,7 +67,7 @@ async def process(self, task: Task) -> ProcessingResult: acknowledgment_reason = self._extract_acknowledgment_reason(comment_body) if not acknowledgment_reason: - logger.info("❌ No valid acknowledgment reason found in comment") + logger.info("no_valid_acknowledgment_reason_found_in") # Post a helpful comment explaining what went wrong help_comment = ( @@ -96,7 +97,7 @@ async def process(self, task: Task) -> ProcessingResult: api_calls += 1 if not github_token: - logger.error(f"❌ Failed to get installation token for {installation_id}") + logger.error("failed_to_get_installation_token_for", installation_id=installation_id) return ProcessingResult( success=False, violations=[], @@ -108,7 +109,7 @@ async def process(self, task: Task) -> ProcessingResult: # Get current PR data and violations pr_data_optional = await self.github_client.get_pull_request(repo, pr_number, installation_id) if not pr_data_optional: - logger.error(f"❌ Failed to get PR data for {repo}#{pr_number}") + logger.error("failed_to_get_pr_data_for", repo=repo, pr_number=pr_number) return ProcessingResult( success=False, violations=[], @@ -171,11 +172,11 @@ async def process(self, task: Task) -> ProcessingResult: logger.info(f"Found {len(all_violations)} total violations") for violation in all_violations: - logger.info(f" β€’ {violation.message}") + logger.info("event", message=violation.message) # Check if the analysis failed due to timeout or other issues if not analysis_result.data or "evaluation_result" not in analysis_result.data: - logger.warning(f"⚠️ Rule analysis failed: {analysis_result.message}") + logger.warning("rule_analysis_failed", message=analysis_result.message) await self._post_comment( repo, pr_number, @@ -194,7 +195,7 @@ async def process(self, task: Task) -> ProcessingResult: ) if not all_violations: - logger.info("βœ… No violations found - acknowledgment not needed") + logger.info("no_violations_found_acknowledgment_not_needed") await self._post_comment( repo, pr_number, installation_id, "βœ… No rule violations detected. Acknowledgment not needed." ) @@ -277,7 +278,7 @@ async def process(self, task: Task) -> ProcessingResult: processing_time = int((time.time() - start_time) * 1000) logger.info("=" * 80) - logger.info(f"🏁 VIOLATION ACKNOWLEDGMENT processing completed in {processing_time}ms") + logger.info("violation_acknowledgment_processing_completed_in_ms", processing_time=processing_time) logger.info(f" Status: {'accepted' if evaluation_result['valid'] else 'rejected'}") logger.info("=" * 80) @@ -340,7 +341,7 @@ async def _evaluate_acknowledgment( Use intelligent LLM-based evaluation to determine which violations can be acknowledged vs. require fixes. """ try: - logger.info("🧠 Using intelligent acknowledgment agent for evaluation") + logger.info("using_intelligent_acknowledgment_agent_for_evaluation") # Use the rules parameter that was passed in (already formatted) # Don't fetch rules again - use the ones passed from the calling method @@ -355,7 +356,7 @@ async def _evaluate_acknowledgment( ) if not agent_result.success: - logger.error(f"🧠 Acknowledgment agent failed: {agent_result.message}") + logger.error("acknowledgment_agent_failed", message=agent_result.message) return { "valid": False, "acknowledgable_violations": [], @@ -374,12 +375,13 @@ async def _evaluate_acknowledgment( confidence = evaluation_data.get("confidence", 0.5) recommendations = evaluation_data.get("recommendations", []) - logger.info("🧠 Intelligent evaluation completed:") - logger.info(f" Valid: {is_valid}") - logger.info(f" Reasoning: {reasoning}") - logger.info(f" Acknowledged violations: {len(acknowledgable_violations)}") - logger.info(f" Require fixes: {len(require_fixes)}") - logger.info(f" Confidence: {confidence}") + logger.info( + "intelligent_evaluation_completed", + is_valid=is_valid, + confidence=confidence, + acknowledged_count=len(acknowledgable_violations), + require_fixes_count=len(require_fixes), + ) return { "valid": is_valid, @@ -396,7 +398,7 @@ async def _evaluate_acknowledgment( } except Exception as e: - logger.error(f"🧠 Error in intelligent acknowledgment evaluation: {e}") + logger.error("error_in_intelligent_acknowledgment_evaluation", e=e) return { "valid": False, "acknowledgable_violations": [], diff --git a/src/integrations/github/check_runs.py b/src/integrations/github/check_runs.py index 84669f7..616f02d 100644 --- a/src/integrations/github/check_runs.py +++ b/src/integrations/github/check_runs.py @@ -1,11 +1,12 @@ -import logging from typing import Any +import structlog + from src.core.models import Violation from src.integrations.github.api import GitHubClient from src.presentation import github_formatter -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class CheckRunManager: @@ -39,7 +40,7 @@ async def create_check_run( """ try: if not sha: - logger.warning(f"Cannot create check run for {repo}: SHA is missing") + logger.warning("cannot_create_check_run_for_sha", repo=repo) return status = "completed" @@ -58,10 +59,10 @@ async def create_check_run( output=output, installation_id=installation_id, ) - logger.info(f"Created check run for {repo}@{sha} with conclusion: {conclusion}") + logger.info("created_check_run_for_with_conclusion", repo=repo, sha=sha, conclusion=conclusion) except Exception as e: - logger.error(f"Error creating check run: {e}") + logger.error("error_creating_check_run", e=e) async def create_acknowledgment_check_run( self, @@ -85,7 +86,7 @@ async def create_acknowledgment_check_run( """ try: if not sha: - logger.warning(f"Cannot create check run for {repo}: SHA is missing") + logger.warning("cannot_create_check_run_for_sha", repo=repo) return # Convert raw dict acknowledgments to Acknowledgment objects if needed @@ -115,7 +116,7 @@ async def create_acknowledgment_check_run( }, installation_id=installation_id, ) - logger.info(f"Created acknowledgment check run for {repo}@{sha}") + logger.info("created_acknowledgment_check_run_for", repo=repo, sha=sha) except Exception as e: - logger.error(f"Error creating check run with acknowledgment: {e}") + logger.error("error_creating_check_run_with_acknowledgment", e=e) diff --git a/src/main.py b/src/main.py index cca8abc..fcf0946 100644 --- a/src/main.py +++ b/src/main.py @@ -1,4 +1,5 @@ import logging +from collections.abc import AsyncIterator from contextlib import asynccontextmanager from typing import Any @@ -53,9 +54,11 @@ format="%(message)s", # structlog handles formatting ) +logger = structlog.get_logger() + @asynccontextmanager -async def lifespan(_app: FastAPI) -> Any: +async def lifespan(_app: FastAPI) -> AsyncIterator[None]: """Application lifespan manager for startup and shutdown logic.""" logging.info("Watchflow application starting up...") @@ -73,26 +76,26 @@ async def lifespan(_app: FastAPI) -> Any: deployment_review_handler = DeploymentReviewEventHandler() deployment_protection_rule_handler = DeploymentProtectionRuleEventHandler() - dispatcher.register_handler(EventType.PULL_REQUEST, pull_request_handler.handle) - dispatcher.register_handler(EventType.PUSH, push_handler.handle) - dispatcher.register_handler(EventType.CHECK_RUN, check_run_handler.handle) - dispatcher.register_handler(EventType.ISSUE_COMMENT, issue_comment_handler.handle) - dispatcher.register_handler(EventType.DEPLOYMENT, deployment_handler.handle) - dispatcher.register_handler(EventType.DEPLOYMENT_STATUS, deployment_status_handler.handle) - dispatcher.register_handler(EventType.DEPLOYMENT_REVIEW, deployment_review_handler.handle) - dispatcher.register_handler(EventType.DEPLOYMENT_PROTECTION_RULE, deployment_protection_rule_handler.handle) + dispatcher.register_handler(EventType.PULL_REQUEST.value, pull_request_handler.handle) + dispatcher.register_handler(EventType.PUSH.value, push_handler.handle) + dispatcher.register_handler(EventType.CHECK_RUN.value, check_run_handler.handle) + dispatcher.register_handler(EventType.ISSUE_COMMENT.value, issue_comment_handler.handle) + dispatcher.register_handler(EventType.DEPLOYMENT.value, deployment_handler.handle) + dispatcher.register_handler(EventType.DEPLOYMENT_STATUS.value, deployment_status_handler.handle) + dispatcher.register_handler(EventType.DEPLOYMENT_REVIEW.value, deployment_review_handler.handle) + dispatcher.register_handler(EventType.DEPLOYMENT_PROTECTION_RULE.value, deployment_protection_rule_handler.handle) - logging.info("Event handlers registered, background workers started, and deployment scheduler started.") + logger.info("Event handlers registered, background workers started, and deployment scheduler started.") yield - logging.info("Watchflow application shutting down...") + logger.info("Watchflow application shutting down...") await get_deployment_scheduler().stop() await task_queue.stop_workers() - logging.info("Background workers and deployment scheduler stopped.") + logger.info("Background workers and deployment scheduler stopped.") app = FastAPI( diff --git a/src/presentation/github_formatter.py b/src/presentation/github_formatter.py index 10df7c9..b904b00 100644 --- a/src/presentation/github_formatter.py +++ b/src/presentation/github_formatter.py @@ -1,9 +1,10 @@ -import logging from typing import Any +import structlog + from src.core.models import Acknowledgment, Severity, Violation -logger = logging.getLogger(__name__) +logger = structlog.get_logger() SEVERITY_EMOJI = { Severity.CRITICAL: "πŸ”΄", diff --git a/src/rules/acknowledgment.py b/src/rules/acknowledgment.py index b6dde80..f82fb20 100644 --- a/src/rules/acknowledgment.py +++ b/src/rules/acknowledgment.py @@ -8,13 +8,14 @@ - Violation text to rule ID mapping """ -import logging import re from enum import StrEnum +import structlog + from src.core.models import Acknowledgment -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class RuleID(StrEnum): @@ -109,7 +110,7 @@ def extract_acknowledgment_reason(comment_body: str) -> str: Returns: The extracted reason string, or empty string if no match. """ - logger.info(f"πŸ” Extracting acknowledgment reason from: '{comment_body}'") + logger.info("extracting_acknowledgment_reason_from", comment_body=comment_body) for i, pattern in enumerate(ACKNOWLEDGMENT_PATTERNS): match = re.search(pattern, comment_body, re.IGNORECASE | re.DOTALL) @@ -118,13 +119,13 @@ def extract_acknowledgment_reason(comment_body: str) -> str: # Patterns 3-7 have reason as group 1 reason = match.group(2).strip() if i < 3 else match.group(1).strip() - logger.info(f"βœ… Pattern {i + 1} matched! Reason: '{reason}'") + logger.info("pattern_matched_reason", reason=reason) if reason: return reason else: - logger.debug(f"❌ Pattern {i + 1} did not match") + logger.debug("pattern_did_not_match") - logger.info("❌ No patterns matched for acknowledgment reason") + logger.info("no_patterns_matched_for_acknowledgment_reason") return "" diff --git a/src/rules/conditions/base.py b/src/rules/conditions/base.py index 7a6de63..35ae080 100644 --- a/src/rules/conditions/base.py +++ b/src/rules/conditions/base.py @@ -3,13 +3,14 @@ This module defines the abstract base class that all conditions must implement. """ -import logging from abc import ABC, abstractmethod from typing import Any +import structlog + from src.core.models import Violation -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class BaseCondition(ABC): diff --git a/src/rules/conditions/filesystem.py b/src/rules/conditions/filesystem.py index cb4e4cb..251904e 100644 --- a/src/rules/conditions/filesystem.py +++ b/src/rules/conditions/filesystem.py @@ -4,14 +4,15 @@ of pull requests and push events. """ -import logging import re from typing import Any +import structlog + from src.core.models import Severity, Violation from src.rules.conditions.base import BaseCondition -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class FilePatternCondition(BaseCondition): @@ -40,7 +41,7 @@ async def evaluate(self, context: Any) -> list[Violation]: pattern = parameters.get("pattern") if not pattern: - logger.warning("FilePatternCondition: No pattern specified in parameters") + logger.warning("filepatterncondition_no_pattern_specified_in_parameters") return [ Violation( rule_description=self.description, @@ -53,7 +54,7 @@ async def evaluate(self, context: Any) -> list[Violation]: changed_files = self._get_changed_files(event) if not changed_files: - logger.debug("No files to check against pattern") + logger.debug("no_files_to_check_against_pattern") return [ Violation( rule_description=self.description, @@ -96,13 +97,13 @@ async def validate(self, parameters: dict[str, Any], event: dict[str, Any]) -> b """Legacy validation interface for backward compatibility.""" pattern = parameters.get("pattern") if not pattern: - logger.warning("FilePatternCondition: No pattern specified in parameters") + logger.warning("filepatterncondition_no_pattern_specified_in_parameters") return False changed_files = self._get_changed_files(event) if not changed_files: - logger.debug("No files to check against pattern") + logger.debug("no_files_to_check_against_pattern") return False regex_pattern = self._glob_to_regex(pattern) @@ -159,7 +160,7 @@ async def evaluate(self, context: Any) -> list[Violation]: files = event.get("files", []) if not files: - logger.debug("MaxFileSizeCondition: No files data available, skipping validation") + logger.debug("maxfilesizecondition_no_files_data_available_skipping") return [] violations: list[Violation] = [] @@ -172,7 +173,7 @@ async def evaluate(self, context: Any) -> list[Violation]: filename = file.get("filename", "unknown") oversized_files.append(f"{filename} ({size_mb:.2f}MB)") logger.debug( - f"MaxFileSizeCondition: File {filename} exceeds size limit: {size_mb:.2f}MB > {max_size_mb}MB" + "maxfilesizecondition_file_exceeds_size_limit_mb", filename=filename, max_size_mb=max_size_mb ) if oversized_files: @@ -196,7 +197,7 @@ async def validate(self, parameters: dict[str, Any], event: dict[str, Any]) -> b files = event.get("files", []) if not files: - logger.debug("MaxFileSizeCondition: No files data available, skipping validation") + logger.debug("maxfilesizecondition_no_files_data_available_skipping") return True oversized_files: list[str] = [] @@ -207,7 +208,7 @@ async def validate(self, parameters: dict[str, Any], event: dict[str, Any]) -> b filename = file.get("filename", "unknown") oversized_files.append(f"{filename} ({size_mb:.2f}MB)") logger.debug( - f"MaxFileSizeCondition: File {filename} exceeds size limit: {size_mb:.2f}MB > {max_size_mb}MB" + "maxfilesizecondition_file_exceeds_size_limit_mb", filename=filename, max_size_mb=max_size_mb ) is_valid = len(oversized_files) == 0 @@ -243,7 +244,7 @@ async def evaluate(self, context: Any) -> list[Violation]: max_lines = parameters.get("max_lines", 0) if not max_lines: - logger.debug("MaxPrLocCondition: No max_lines specified, skipping validation") + logger.debug("maxprloccondition_no_maxlines_specified_skipping_validation") return [] changed_files = event.get("changed_files", []) or event.get("files", []) diff --git a/src/rules/conditions/pull_request.py b/src/rules/conditions/pull_request.py index 122923c..0b395ec 100644 --- a/src/rules/conditions/pull_request.py +++ b/src/rules/conditions/pull_request.py @@ -4,14 +4,15 @@ such as title patterns, description length, and required labels. """ -import logging import re from typing import Any +import structlog + from src.core.models import Severity, Violation from src.rules.conditions.base import BaseCondition -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class TitlePatternCondition(BaseCondition): @@ -56,7 +57,7 @@ async def evaluate(self, context: Any) -> list[Violation]: try: matches = bool(re.match(pattern, title)) - logger.debug(f"TitlePatternCondition: Title '{title}' matches pattern '{pattern}': {matches}") + logger.debug("titlepatterncondition_title_matches_pattern", title=title, pattern=pattern, matches=matches) if not matches: return [ @@ -69,7 +70,7 @@ async def evaluate(self, context: Any) -> list[Violation]: ) ] except re.error as e: - logger.error(f"TitlePatternCondition: Invalid regex pattern '{pattern}': {e}") + logger.error("titlepatterncondition_invalid_regex_pattern", pattern=pattern, e=e) return [] # No violation if pattern is invalid return [] @@ -90,10 +91,10 @@ async def validate(self, parameters: dict[str, Any], event: dict[str, Any]) -> b try: matches = bool(re.match(pattern, title)) - logger.debug(f"TitlePatternCondition: Title '{title}' matches pattern '{pattern}': {matches}") + logger.debug("titlepatterncondition_title_matches_pattern", title=title, pattern=pattern, matches=matches) return matches except re.error as e: - logger.error(f"TitlePatternCondition: Invalid regex pattern '{pattern}': {e}") + logger.error("titlepatterncondition_invalid_regex_pattern", pattern=pattern, e=e) return True # No violation if pattern is invalid @@ -139,7 +140,10 @@ async def evaluate(self, context: Any) -> list[Violation]: is_valid = description_length >= min_length logger.debug( - f"MinDescriptionLengthCondition: Description length {description_length}, requires {min_length}: {is_valid}" + "mindescriptionlengthcondition_description_length_requires", + description_length=description_length, + min_length=min_length, + is_valid=is_valid, ) if not is_valid: @@ -171,7 +175,10 @@ async def validate(self, parameters: dict[str, Any], event: dict[str, Any]) -> b is_valid = description_length >= min_length logger.debug( - f"MinDescriptionLengthCondition: Description length {description_length}, requires {min_length}: {is_valid}" + "mindescriptionlengthcondition_description_length_requires", + description_length=description_length, + min_length=min_length, + is_valid=is_valid, ) return is_valid @@ -211,7 +218,10 @@ async def evaluate(self, context: Any) -> list[Violation]: missing_labels = [label for label in required_labels if label not in pr_labels] logger.debug( - f"RequiredLabelsCondition: PR has labels {pr_labels}, requires {required_labels}, missing {missing_labels}" + "requiredlabelscondition_pr_has_labels_requires_missing", + pr_labels=pr_labels, + required_labels=required_labels, + missing_labels=missing_labels, ) if missing_labels: @@ -248,7 +258,11 @@ async def validate(self, parameters: dict[str, Any], event: dict[str, Any]) -> b is_valid = len(missing_labels) == 0 logger.debug( - f"RequiredLabelsCondition: PR has labels {pr_labels}, requires {required_labels}, missing {missing_labels}: {is_valid}" + "requiredlabelscondition_pr_has_labels_requires_missing", + pr_labels=pr_labels, + required_labels=required_labels, + missing_labels=missing_labels, + is_valid=is_valid, ) return is_valid @@ -340,7 +354,7 @@ async def evaluate(self, context: Any) -> list[Violation]: combined = f"{title}\n{body}" if _ISSUE_REF_PATTERN.search(combined): - logger.debug("RequireLinkedIssueCondition: PR references an issue") + logger.debug("requirelinkedissuecondition_pr_references_an_issue") return [] return [ diff --git a/src/rules/loaders/github_loader.py b/src/rules/loaders/github_loader.py index 0848bad..a911c86 100644 --- a/src/rules/loaders/github_loader.py +++ b/src/rules/loaders/github_loader.py @@ -4,9 +4,9 @@ Loads rules from GitHub repository files, implementing the RuleLoader interface. """ -import logging from typing import Any +import structlog import yaml from src.core.config import config @@ -16,7 +16,7 @@ from src.rules.models import Rule, RuleAction, RuleSeverity from src.rules.registry import CONDITION_CLASS_TO_RULE_ID, ConditionRegistry -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class RulesFileNotFoundError(Exception): @@ -42,17 +42,17 @@ async def get_rules(self, repository: str, installation_id: int) -> list[Rule]: logger.info(f"Fetching rules for repository: {repository} (installation: {installation_id})") content = await self.github_client.get_file_content(repository, rules_file_path, installation_id) if not content: - logger.warning(f"No rules.yaml file found in {repository}") + logger.warning("no_rulesyaml_file_found_in", repository=repository) raise RulesFileNotFoundError(f"Rules file not found: {rules_file_path}") rules_data = yaml.safe_load(content) if not isinstance(rules_data, dict) or "rules" not in rules_data: - logger.warning(f"No rules found in {repository}/{rules_file_path}") + logger.warning("no_rules_found_in", repository=repository, rules_file_path=rules_file_path) return [] rules = [] if not isinstance(rules_data["rules"], list): - logger.warning(f"Rules key is not a list in {repository}/{rules_file_path}") + logger.warning("rules_key_is_not_a_list", repository=repository, rules_file_path=rules_file_path) return [] for rule_data in rules_data["rules"]: @@ -64,7 +64,7 @@ async def get_rules(self, repository: str, installation_id: int) -> list[Rule]: rules.append(rule) except Exception as e: rule_description = rule_data.get("description", "unknown") - logger.error(f"Error parsing rule {rule_description}: {e}") + logger.error("error_parsing_rule", rule_description=rule_description, e=e) continue logger.info(f"Successfully loaded {len(rules)} rules from {repository}") @@ -73,7 +73,7 @@ async def get_rules(self, repository: str, installation_id: int) -> list[Rule]: # Re-raise this specific exception raise except Exception as e: - logger.error(f"Error fetching rules for {repository}: {e}") + logger.error("error_fetching_rules_for", repository=repository, e=e) raise @staticmethod @@ -89,7 +89,7 @@ def _parse_rule(rule_data: dict[str, Any]) -> Rule: event_type = EventType(event_type_str) event_types.append(event_type) except ValueError: - logger.warning(f"Unknown event type: {event_type_str}") + logger.warning("unknown_event_type", event_type_str=event_type_str) # Get parameters (strip internal "validator" key; engine infers validator from parameter names) parameters = dict(rule_data.get("parameters", {})) diff --git a/src/rules/models.py b/src/rules/models.py index 874876a..dbaf9f5 100644 --- a/src/rules/models.py +++ b/src/rules/models.py @@ -1,6 +1,6 @@ from __future__ import annotations -from enum import Enum +from enum import StrEnum from typing import Any from pydantic import BaseModel, ConfigDict, Field @@ -9,7 +9,7 @@ from src.rules.conditions.base import BaseCondition # noqa: TCH001, TCH002, TC001 -class RuleSeverity(str, Enum): +class RuleSeverity(StrEnum): """Enumerates the severity levels of a rule violation.""" LOW = "low" @@ -20,7 +20,7 @@ class RuleSeverity(str, Enum): WARNING = "warning" # Added for backward compatibility -class RuleCategory(str, Enum): +class RuleCategory(StrEnum): """Enumerates rule categories for organizational and filtering purposes.""" SECURITY = "security" # Authentication, secrets, CVE scanning diff --git a/src/rules/registry.py b/src/rules/registry.py index af5aac6..6772962 100644 --- a/src/rules/registry.py +++ b/src/rules/registry.py @@ -5,7 +5,7 @@ enabling dynamic loading and execution of rules. """ -import logging +import structlog from src.rules.acknowledgment import RuleID from src.rules.conditions.access_control import ( @@ -36,7 +36,7 @@ ) from src.rules.conditions.workflow import WorkflowDurationCondition -logger = logging.getLogger(__name__) +logger = structlog.get_logger() # Map RuleID to Condition classes RULE_ID_TO_CONDITION: dict[RuleID, type[BaseCondition]] = { @@ -111,8 +111,8 @@ def get_conditions_for_parameters(parameters: dict) -> list[BaseCondition]: try: condition = condition_cls() matched_conditions.append(condition) - logger.debug(f"Matches condition: {condition_cls.name}") + logger.debug("matches_condition", name=condition_cls.name) except Exception as e: - logger.error(f"Failed to instantiate condition {condition_cls.name}: {e}") + logger.error("failed_to_instantiate_condition", name=condition_cls.name, e=e) return matched_conditions diff --git a/src/rules/utils.py b/src/rules/utils.py index 478b230..804fa32 100644 --- a/src/rules/utils.py +++ b/src/rules/utils.py @@ -1,12 +1,12 @@ -import logging from typing import Any +import structlog import yaml from src.integrations.github import github_client from src.rules.models import Rule -logger = logging.getLogger(__name__) +logger = structlog.get_logger() DOCS_URL = "https://github.com/warestack/watchflow/blob/main/docs/getting-started/configuration.md" @@ -21,7 +21,7 @@ async def validate_rules_yaml_from_repo(repo_full_name: str, installation_id: in comment=validation_result["message"], installation_id=installation_id, ) - logger.info(f"Posted validation result to PR #{pr_number} in {repo_full_name}") + logger.info("posted_validation_result_to_pr_in", pr_number=pr_number, repo_full_name=repo_full_name) async def _validate_rules_yaml(repo: str, installation_id: int) -> dict[str, Any]: diff --git a/src/rules/utils/codeowners.py b/src/rules/utils/codeowners.py index 2d5df3b..328cdb1 100644 --- a/src/rules/utils/codeowners.py +++ b/src/rules/utils/codeowners.py @@ -5,11 +5,12 @@ requirements and determine critical file patterns. """ -import logging import re from pathlib import Path -logger = logging.getLogger(__name__) +import structlog + +logger = structlog.get_logger() class CodeOwnersParser: @@ -38,7 +39,7 @@ def _parse_codeowners(self) -> list[tuple[str, list[str]]]: # Split on whitespace, first part is pattern, rest are owners parts = line.split() if len(parts) < 2: - logger.warning(f"Invalid CODEOWNERS line {line_num}: {line}") + logger.warning("invalid_codeowners_line", line_num=line_num, line=line) continue pattern = parts[0] @@ -98,7 +99,7 @@ def _matches_pattern(self, file_path: str, pattern: str) -> bool: try: return bool(re.match(regex_pattern, file_path)) except re.error: - logger.error(f"Invalid regex pattern: {regex_pattern}") + logger.error("invalid_regex_pattern", regex_pattern=regex_pattern) return False @staticmethod @@ -189,7 +190,7 @@ def load_codeowners(repo_path: str = ".") -> CodeOwnersParser | None: codeowners_path = Path(repo_path) / "CODEOWNERS" if not codeowners_path.exists(): - logger.warning(f"CODEOWNERS file not found at {codeowners_path}") + logger.warning("codeowners_file_not_found_at", codeowners_path=codeowners_path) return None try: @@ -198,7 +199,7 @@ def load_codeowners(repo_path: str = ".") -> CodeOwnersParser | None: return CodeOwnersParser(content) except Exception as e: - logger.error(f"Error loading CODEOWNERS file: {e}") + logger.error("error_loading_codeowners_file", e=e) return None diff --git a/src/rules/utils/contributors.py b/src/rules/utils/contributors.py index b4a2f36..a530eb7 100644 --- a/src/rules/utils/contributors.py +++ b/src/rules/utils/contributors.py @@ -5,13 +5,14 @@ and determine if users are new or established contributors. """ -import logging from datetime import datetime, timedelta from typing import Any +import structlog + from src.core.utils.caching import AsyncCache -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class ContributorAnalyzer: @@ -42,11 +43,11 @@ async def get_past_contributors( # Check cache first cached_value = self._contributors_cache.get(cache_key) if cached_value is not None: - logger.debug(f"Using cached past contributors for {repo}") + logger.debug("using_cached_past_contributors_for", repo=repo) return set(cached_value) try: - logger.info(f"Fetching past contributors for {repo}") + logger.info("fetching_past_contributors_for", repo=repo) # Get contributors from GitHub API contributors = await self._fetch_contributors(repo, installation_id) @@ -72,7 +73,7 @@ async def get_past_contributors( return past_contributors except Exception as e: - logger.error(f"Error fetching past contributors for {repo}: {e}") + logger.error("error_fetching_past_contributors_for", repo=repo, e=e) return set() async def is_new_contributor( @@ -98,11 +99,11 @@ async def is_new_contributor( # Check if user is in the past contributors list is_new = username not in past_contributors - logger.debug(f"User {username} is {'new' if is_new else 'established'} contributor in {repo}") + logger.debug("user_is_contributor_in", username=username, repo=repo) return is_new except Exception as e: - logger.error(f"Error checking if {username} is new contributor in {repo}: {e}") + logger.error("error_checking_if_is_new_contributor", username=username, repo=repo, e=e) # Default to treating as new contributor on error return True @@ -164,7 +165,7 @@ async def get_user_contribution_stats(self, username: str, repo: str, installati return stats except Exception as e: - logger.error(f"Error getting contribution stats for {username} in {repo}: {e}") + logger.error("error_getting_contribution_stats_for_in", username=username, repo=repo, e=e) return { "username": username, "total_commits": 0, @@ -184,7 +185,7 @@ async def _fetch_contributors(self, repo: str, installation_id: int) -> list[dic contributors = await self.github_client.get_repository_contributors(repo, installation_id) return cast("list[dict[str, Any]]", contributors or []) except Exception as e: - logger.error(f"Error fetching contributors for {repo}: {e}") + logger.error("error_fetching_contributors_for", repo=repo, e=e) return [] async def _has_recent_activity(self, repo: str, username: str, installation_id: int, cutoff_date: datetime) -> bool: @@ -213,7 +214,7 @@ async def _has_recent_activity(self, repo: str, username: str, installation_id: return False except Exception as e: - logger.error(f"Error checking recent activity for {username} in {repo}: {e}") + logger.error("error_checking_recent_activity_for_in", username=username, repo=repo, e=e) return False async def _fetch_user_commits( @@ -228,7 +229,7 @@ async def _fetch_user_commits( await self.github_client.get_user_commits(repo, username, installation_id, limit), ) except Exception as e: - logger.error(f"Error fetching commits for {username} in {repo}: {e}") + logger.error("error_fetching_commits_for_in", username=username, repo=repo, e=e) return [] async def _fetch_user_pull_requests( @@ -243,7 +244,7 @@ async def _fetch_user_pull_requests( await self.github_client.get_user_pull_requests(repo, username, installation_id, limit), ) except Exception as e: - logger.error(f"Error fetching PRs for {username} in {repo}: {e}") + logger.error("error_fetching_prs_for_in", username=username, repo=repo, e=e) return [] async def _fetch_user_issues( @@ -257,7 +258,7 @@ async def _fetch_user_issues( "list[dict[str, Any]]", await self.github_client.get_user_issues(repo, username, installation_id, limit) ) except Exception as e: - logger.error(f"Error fetching issues for {username} in {repo}: {e}") + logger.error("error_fetching_issues_for_in", username=username, repo=repo, e=e) return [] diff --git a/src/rules/utils/validation.py b/src/rules/utils/validation.py index 1152407..1ab4b48 100644 --- a/src/rules/utils/validation.py +++ b/src/rules/utils/validation.py @@ -4,15 +4,15 @@ Functions for validating rule YAML files and posting validation results. """ -import logging from typing import Any +import structlog import yaml # type: ignore from src.integrations.github import github_client from src.rules.models import Rule -logger = logging.getLogger(__name__) +logger = structlog.get_logger() DOCS_URL = "https://github.com/warestack/watchflow/blob/main/docs/getting-started/configuration.md" @@ -28,7 +28,7 @@ async def validate_rules_yaml_from_repo(repo_full_name: str, installation_id: in comment=validation_result["message"], installation_id=installation_id, ) - logger.info(f"Posted validation result to PR #{pr_number} in {repo_full_name}") + logger.info("posted_validation_result_to_pr_in", pr_number=pr_number, repo_full_name=repo_full_name) async def _validate_rules_yaml(repo: str, installation_id: int) -> dict[str, Any]: diff --git a/src/webhooks/handlers/deployment_review.py b/src/webhooks/handlers/deployment_review.py index 7417e89..e57a616 100644 --- a/src/webhooks/handlers/deployment_review.py +++ b/src/webhooks/handlers/deployment_review.py @@ -1,11 +1,11 @@ -import logging +import structlog from src.core.models import EventType, WebhookEvent, WebhookResponse from src.event_processors.deployment_review import DeploymentReviewProcessor from src.tasks.task_queue import task_queue from src.webhooks.handlers.base import EventHandler -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class DeploymentReviewEventHandler(EventHandler): @@ -16,7 +16,7 @@ async def can_handle(self, event: WebhookEvent) -> bool: async def handle(self, event: WebhookEvent) -> WebhookResponse: """Handle deployment review events by enqueuing them for background processing.""" - logger.info(f"πŸ”„ Enqueuing deployment review event for {event.repo_full_name}") + logger.info("enqueuing_deployment_review_event_for", repo_full_name=event.repo_full_name) task_id = await task_queue.enqueue( DeploymentReviewProcessor().process, @@ -26,7 +26,7 @@ async def handle(self, event: WebhookEvent) -> WebhookResponse: payload=event.payload, ) - logger.info(f"βœ… Deployment review event enqueued with task ID: {task_id}") + logger.info("deployment_review_event_enqueued_with_task", task_id=task_id) return WebhookResponse( status="ok", diff --git a/src/webhooks/handlers/deployment_status.py b/src/webhooks/handlers/deployment_status.py index 21a16a1..2e0851b 100644 --- a/src/webhooks/handlers/deployment_status.py +++ b/src/webhooks/handlers/deployment_status.py @@ -1,10 +1,10 @@ -import logging +import structlog from src.core.models import EventType, WebhookEvent, WebhookResponse from src.tasks.task_queue import task_queue from src.webhooks.handlers.base import EventHandler -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class DeploymentStatusEventHandler(EventHandler): @@ -20,7 +20,7 @@ async def handle(self, event: WebhookEvent) -> WebhookResponse: installation_id = payload.get("installation", {}).get("id") if not installation_id: - logger.error(f"No installation ID found in deployment_status event for {repo_full_name}") + logger.error("no_installation_id_found_in_deploymentstatus", repo_full_name=repo_full_name) return WebhookResponse(status="error", detail="Missing installation ID") # Extract statusβ€”fragile if GitHub changes payload structure. @@ -28,8 +28,8 @@ async def handle(self, event: WebhookEvent) -> WebhookResponse: deployment = payload.get("deployment", {}) state = deployment_status.get("state", "") - logger.info(f"πŸ”„ Enqueuing deployment status event for {repo_full_name}") - logger.info(f" State: {state}") + logger.info("enqueuing_deployment_status_event_for", repo_full_name=repo_full_name) + logger.info("state", state=state) logger.info(f" Environment: {deployment.get('environment', 'unknown')}") from src.event_processors.deployment_status import DeploymentStatusProcessor @@ -43,7 +43,7 @@ async def handle(self, event: WebhookEvent) -> WebhookResponse: payload=payload, ) - logger.info(f"βœ… Deployment status event enqueued with task ID: {task_id}") + logger.info("deployment_status_event_enqueued_with_task", task_id=task_id) return WebhookResponse( status="ok", diff --git a/src/webhooks/handlers/issue_comment.py b/src/webhooks/handlers/issue_comment.py index 687831f..683d2ca 100644 --- a/src/webhooks/handlers/issue_comment.py +++ b/src/webhooks/handlers/issue_comment.py @@ -1,6 +1,7 @@ -import logging import re +import structlog + from src.agents import get_agent from src.core.models import EventType, WebhookEvent from src.integrations.github import github_client @@ -8,7 +9,7 @@ from src.tasks.task_queue import task_queue from src.webhooks.handlers.base import EventHandler, WebhookResponse -logger = logging.getLogger(__name__) +logger = structlog.get_logger() class IssueCommentEventHandler(EventHandler): @@ -34,10 +35,10 @@ async def handle(self, event: WebhookEvent) -> WebhookResponse: # Bot self-reply guardβ€”avoids infinite loop, spam. bot_usernames = ["watchflow[bot]", "watchflow-bot", "watchflow", "watchflowbot", "watchflow_bot"] if commenter and any(bot_name.lower() in commenter.lower() for bot_name in bot_usernames): - logger.info(f"πŸ€– Ignoring comment from bot user: {commenter}") + logger.info("ignoring_comment_from_bot_user", commenter=commenter) return WebhookResponse(status="ignored", detail="Bot comment") - logger.info(f"πŸ‘€ Processing comment from human user: {commenter}") + logger.info("processing_comment_from_human_user", commenter=commenter) # Help commandβ€”user likely lost/confused. if self._is_help_comment(comment_body): @@ -49,7 +50,7 @@ async def handle(self, event: WebhookEvent) -> WebhookResponse: "- @watchflow validate β€” Validate the .watchflow/rules.yaml file.\n" "- @watchflow help β€” Show this help message.\n" ) - logger.info("ℹ️ Responding to help command.") + logger.info("responding_to_help_command") pr_number = ( event.payload.get("issue", {}).get("number") or event.payload.get("pull_request", {}).get("number") @@ -62,10 +63,10 @@ async def handle(self, event: WebhookEvent) -> WebhookResponse: comment=help_message, installation_id=installation_id, ) - logger.info(f"ℹ️ Posted help message as a comment to PR/issue #{pr_number}.") + logger.info("posted_help_message_as_a_comment", pr_number=pr_number) return WebhookResponse(status="ok") else: - logger.warning("Could not determine PR or issue number to post help message.") + logger.warning("could_not_determine_pr_or_issue") return WebhookResponse(status="ok", detail=help_message) # Acknowledgmentβ€”user wants to mark violation as known/accepted. @@ -89,7 +90,7 @@ async def process_acknowledgment(acknowledgment_task: Task) -> None: "violation_acknowledgment", ack_payload, ) - logger.info(f"βœ… Acknowledgment comment enqueued: {result}") + logger.info("acknowledgment_comment_enqueued", result=result) return WebhookResponse( status="ok", detail=f"Acknowledgment enqueued with reason: {ack_reason}", @@ -124,15 +125,15 @@ async def process_acknowledgment(acknowledgment_task: Task) -> None: comment=comment, installation_id=installation_id, ) - logger.info(f"πŸ“ Posted feasibility evaluation result as a comment to PR/issue #{pr_number}.") + logger.info("posted_feasibility_evaluation_result_as_a", pr_number=pr_number) return WebhookResponse(status="ok") else: - logger.warning("Could not determine PR or issue number to post feasibility evaluation result.") + logger.warning("could_not_determine_pr_or_issue") return WebhookResponse(status="ok", detail=comment) # Validateβ€”user wants rules.yaml sanity check. if self._is_validate_comment(comment_body): - logger.info("πŸ” Processing validate command.") + logger.info("processing_validate_command") validation_result = await _validate_rules_yaml(repo, installation_id) pr_number = ( event.payload.get("issue", {}).get("number") @@ -146,15 +147,15 @@ async def process_acknowledgment(acknowledgment_task: Task) -> None: comment=str(validation_result), installation_id=installation_id, ) - logger.info(f"βœ… Posted validation result as a comment to PR/issue #{pr_number}.") + logger.info("posted_validation_result_as_a_comment", pr_number=pr_number) return WebhookResponse(status="ok") else: - logger.warning("Could not determine PR or issue number to post validation result.") + logger.warning("could_not_determine_pr_or_issue") return WebhookResponse(status="ok", detail=str(validation_result)) else: # No matchβ€”ignore, avoid noise. - logger.info("πŸ“‹ Comment does not match any known patterns - ignoring") + logger.info("comment_does_not_match_any_known") return WebhookResponse(status="ignored", detail="No matching patterns") except Exception as e: @@ -165,7 +166,7 @@ def _extract_acknowledgment_reason(self, comment_body: str) -> str | None: """Extract the quoted reason from an acknowledgment command, or None if not present.""" comment_body = comment_body.strip() - logger.info("extracting_acknowledgment_reason") + logger.info("extractingacknowledgmentreason") # Regex flexibilityβ€”users type commands in unpredictable ways. patterns = [ @@ -174,18 +175,18 @@ def _extract_acknowledgment_reason(self, comment_body: str) -> str | None: r"@watchflow\s+(acknowledge|ack)\s+([^\n\r]+)", # No quotesβ€”last resort ] - for i, pattern in enumerate(patterns): + for _i, pattern in enumerate(patterns): match = re.search(pattern, comment_body, re.IGNORECASE | re.DOTALL) if match: # All patterns: group 2 = reason. Brittle if GitHub changes format. reason = match.group(2).strip() - logger.info(f"βœ… Pattern {i + 1} matched! Reason: '{reason}'") + logger.info("pattern_matched_reason", reason=reason) if reason: # Defensive: skip empty reasonsβ€”user typo, bot spam. return reason else: - logger.info(f"❌ Pattern {i + 1} did not match") + logger.info("pattern_did_not_match") - logger.info("❌ No patterns matched for acknowledgment reason") + logger.info("no_patterns_matched_for_acknowledgment_reason") return None def _extract_evaluate_rule(self, comment_body: str) -> str | None: