diff --git a/lib/crewai/src/crewai/agents/crew_agent_executor.py b/lib/crewai/src/crewai/agents/crew_agent_executor.py index de19934d6..6c0d8fded 100644 --- a/lib/crewai/src/crewai/agents/crew_agent_executor.py +++ b/lib/crewai/src/crewai/agents/crew_agent_executor.py @@ -219,6 +219,7 @@ class CrewAgentExecutor(CrewAgentExecutorMixin): Final answer from the agent. """ formatted_answer = None + last_raw_output: str | None = None while not isinstance(formatted_answer, AgentFinish): try: if has_reached_max_iterations(self.iterations, self.max_iter): @@ -244,6 +245,7 @@ class CrewAgentExecutor(CrewAgentExecutorMixin): response_model=self.response_model, executor_context=self, ) + last_raw_output = answer if self.response_model is not None: try: self.response_model.model_validate_json(answer) @@ -300,6 +302,8 @@ class CrewAgentExecutor(CrewAgentExecutorMixin): iterations=self.iterations, log_error_after=self.log_error_after, printer=self._printer, + raw_output=last_raw_output, + agent_role=self.agent.role if self.agent else None, ) except Exception as e: @@ -386,6 +390,7 @@ class CrewAgentExecutor(CrewAgentExecutorMixin): Final answer from the agent. """ formatted_answer = None + last_raw_output: str | None = None while not isinstance(formatted_answer, AgentFinish): try: if has_reached_max_iterations(self.iterations, self.max_iter): @@ -411,6 +416,7 @@ class CrewAgentExecutor(CrewAgentExecutorMixin): response_model=self.response_model, executor_context=self, ) + last_raw_output = answer if self.response_model is not None: try: @@ -467,6 +473,8 @@ class CrewAgentExecutor(CrewAgentExecutorMixin): iterations=self.iterations, log_error_after=self.log_error_after, printer=self._printer, + raw_output=last_raw_output, + agent_role=self.agent.role if self.agent else None, ) except Exception as e: diff --git a/lib/crewai/src/crewai/lite_agent.py b/lib/crewai/src/crewai/lite_agent.py index 9bb3193e5..0c80bd380 100644 --- a/lib/crewai/src/crewai/lite_agent.py +++ b/lib/crewai/src/crewai/lite_agent.py @@ -533,6 +533,7 @@ class LiteAgent(FlowTrackable, BaseModel): """ # Execute the agent loop formatted_answer: AgentAction | AgentFinish | None = None + last_raw_output: str | None = None while not isinstance(formatted_answer, AgentFinish): try: if has_reached_max_iterations(self._iterations, self.max_iterations): @@ -556,6 +557,7 @@ class LiteAgent(FlowTrackable, BaseModel): from_agent=self, executor_context=self, ) + last_raw_output = answer except Exception as e: raise e @@ -594,6 +596,8 @@ class LiteAgent(FlowTrackable, BaseModel): iterations=self._iterations, log_error_after=3, printer=self._printer, + raw_output=last_raw_output, + agent_role=self.role, ) except Exception as e: diff --git a/lib/crewai/src/crewai/utilities/agent_utils.py b/lib/crewai/src/crewai/utilities/agent_utils.py index 973ad5596..b9524f1bf 100644 --- a/lib/crewai/src/crewai/utilities/agent_utils.py +++ b/lib/crewai/src/crewai/utilities/agent_utils.py @@ -2,6 +2,7 @@ from __future__ import annotations from collections.abc import Callable, Sequence import json +import logging import re from typing import TYPE_CHECKING, Any, Final, Literal, TypedDict @@ -51,6 +52,8 @@ class SummaryContent(TypedDict): console = Console() +logger = logging.getLogger(__name__) + _MULTIPLE_NEWLINES: Final[re.Pattern[str]] = re.compile(r"\n+") @@ -430,6 +433,8 @@ def handle_output_parser_exception( iterations: int, log_error_after: int = 3, printer: Printer | None = None, + raw_output: str | None = None, + agent_role: str | None = None, ) -> AgentAction: """Handle OutputParserError by updating messages and formatted_answer. @@ -439,6 +444,8 @@ def handle_output_parser_exception( iterations: Current iteration count log_error_after: Number of iterations after which to log errors printer: Optional printer instance for logging + raw_output: The raw LLM output that failed to parse + agent_role: The role of the agent for logging context Returns: AgentAction: A formatted answer with the error @@ -452,6 +459,27 @@ def handle_output_parser_exception( thought="", ) + retry_count = iterations + 1 + agent_context = f" for agent '{agent_role}'" if agent_role else "" + + logger.debug( + "Parse failed%s: %s", + agent_context, + e.error.split("\n")[0], + ) + + if raw_output is not None: + truncated_output = ( + raw_output[:500] + "..." if len(raw_output) > 500 else raw_output + ) + logger.debug( + "Raw output (truncated)%s: %s", + agent_context, + truncated_output.replace("\n", "\\n"), + ) + + logger.debug("Retry %d initiated%s", retry_count, agent_context) + if iterations > log_error_after and printer: printer.print( content=f"Error parsing LLM output, agent will retry: {e.error}", diff --git a/lib/crewai/tests/utilities/test_agent_utils.py b/lib/crewai/tests/utilities/test_agent_utils.py new file mode 100644 index 000000000..0b9a1e91d --- /dev/null +++ b/lib/crewai/tests/utilities/test_agent_utils.py @@ -0,0 +1,240 @@ +"""Tests for agent_utils module, specifically debug logging for OutputParserError.""" + +import logging +from unittest.mock import MagicMock + +import pytest + +from crewai.agents.parser import AgentAction, OutputParserError +from crewai.utilities.agent_utils import handle_output_parser_exception + + +class TestHandleOutputParserExceptionDebugLogging: + """Tests for debug logging in handle_output_parser_exception.""" + + def test_debug_logging_with_raw_output_and_agent_role(self, caplog: pytest.LogCaptureFixture) -> None: + """Test that debug logging includes raw output and agent role when provided.""" + error = OutputParserError("Invalid Format: I missed the 'Action:' after 'Thought:'.") + messages: list[dict[str, str]] = [] + raw_output = "Let me think about this... The answer is..." + agent_role = "Researcher" + + with caplog.at_level(logging.DEBUG): + result = handle_output_parser_exception( + e=error, + messages=messages, + iterations=0, + raw_output=raw_output, + agent_role=agent_role, + ) + + assert isinstance(result, AgentAction) + assert "Parse failed for agent 'Researcher'" in caplog.text + assert "Raw output (truncated) for agent 'Researcher'" in caplog.text + assert "Let me think about this... The answer is..." in caplog.text + assert "Retry 1 initiated for agent 'Researcher'" in caplog.text + + def test_debug_logging_without_agent_role(self, caplog: pytest.LogCaptureFixture) -> None: + """Test that debug logging works without agent role.""" + error = OutputParserError("Invalid Format: I missed the 'Action:' after 'Thought:'.") + messages: list[dict[str, str]] = [] + raw_output = "Some raw output" + + with caplog.at_level(logging.DEBUG): + result = handle_output_parser_exception( + e=error, + messages=messages, + iterations=0, + raw_output=raw_output, + ) + + assert isinstance(result, AgentAction) + assert "Parse failed:" in caplog.text + assert "for agent" not in caplog.text.split("Parse failed:")[1].split("\n")[0] + assert "Raw output (truncated):" in caplog.text + assert "Retry 1 initiated" in caplog.text + + def test_debug_logging_without_raw_output(self, caplog: pytest.LogCaptureFixture) -> None: + """Test that debug logging works without raw output.""" + error = OutputParserError("Invalid Format: I missed the 'Action:' after 'Thought:'.") + messages: list[dict[str, str]] = [] + + with caplog.at_level(logging.DEBUG): + result = handle_output_parser_exception( + e=error, + messages=messages, + iterations=0, + agent_role="Researcher", + ) + + assert isinstance(result, AgentAction) + assert "Parse failed for agent 'Researcher'" in caplog.text + assert "Raw output (truncated)" not in caplog.text + assert "Retry 1 initiated for agent 'Researcher'" in caplog.text + + def test_debug_logging_truncates_long_raw_output(self, caplog: pytest.LogCaptureFixture) -> None: + """Test that raw output is truncated when longer than 500 characters.""" + error = OutputParserError("Invalid Format") + messages: list[dict[str, str]] = [] + long_output = "A" * 600 + + with caplog.at_level(logging.DEBUG): + handle_output_parser_exception( + e=error, + messages=messages, + iterations=0, + raw_output=long_output, + agent_role="Researcher", + ) + + assert "A" * 500 + "..." in caplog.text + assert "A" * 600 not in caplog.text + + def test_debug_logging_does_not_truncate_short_raw_output(self, caplog: pytest.LogCaptureFixture) -> None: + """Test that short raw output is not truncated.""" + error = OutputParserError("Invalid Format") + messages: list[dict[str, str]] = [] + short_output = "Short output" + + with caplog.at_level(logging.DEBUG): + handle_output_parser_exception( + e=error, + messages=messages, + iterations=0, + raw_output=short_output, + agent_role="Researcher", + ) + + assert "Short output" in caplog.text + assert "..." not in caplog.text.split("Short output")[1].split("\n")[0] + + def test_debug_logging_retry_count_increments(self, caplog: pytest.LogCaptureFixture) -> None: + """Test that retry count is correctly calculated from iterations.""" + error = OutputParserError("Invalid Format") + messages: list[dict[str, str]] = [] + + with caplog.at_level(logging.DEBUG): + handle_output_parser_exception( + e=error, + messages=messages, + iterations=4, + raw_output="test", + agent_role="Researcher", + ) + + assert "Retry 5 initiated" in caplog.text + + def test_debug_logging_escapes_newlines_in_raw_output(self, caplog: pytest.LogCaptureFixture) -> None: + """Test that newlines in raw output are escaped for readability.""" + error = OutputParserError("Invalid Format") + messages: list[dict[str, str]] = [] + output_with_newlines = "Line 1\nLine 2\nLine 3" + + with caplog.at_level(logging.DEBUG): + handle_output_parser_exception( + e=error, + messages=messages, + iterations=0, + raw_output=output_with_newlines, + agent_role="Researcher", + ) + + assert "Line 1\\nLine 2\\nLine 3" in caplog.text + + def test_debug_logging_extracts_first_line_of_error(self, caplog: pytest.LogCaptureFixture) -> None: + """Test that only the first line of the error message is logged.""" + error = OutputParserError("First line of error\nSecond line\nThird line") + messages: list[dict[str, str]] = [] + + with caplog.at_level(logging.DEBUG): + handle_output_parser_exception( + e=error, + messages=messages, + iterations=0, + agent_role="Researcher", + ) + + assert "First line of error" in caplog.text + parse_failed_line = [line for line in caplog.text.split("\n") if "Parse failed" in line][0] + assert "Second line" not in parse_failed_line + + def test_messages_updated_with_error(self) -> None: + """Test that messages list is updated with the error.""" + error = OutputParserError("Test error message") + messages: list[dict[str, str]] = [] + + handle_output_parser_exception( + e=error, + messages=messages, + iterations=0, + ) + + assert len(messages) == 1 + assert messages[0]["role"] == "user" + assert messages[0]["content"] == "Test error message" + + def test_returns_agent_action_with_error_text(self) -> None: + """Test that the function returns an AgentAction with the error text.""" + error = OutputParserError("Test error message") + messages: list[dict[str, str]] = [] + + result = handle_output_parser_exception( + e=error, + messages=messages, + iterations=0, + ) + + assert isinstance(result, AgentAction) + assert result.text == "Test error message" + assert result.tool == "" + assert result.tool_input == "" + assert result.thought == "" + + def test_printer_logs_after_log_error_after_iterations(self) -> None: + """Test that printer logs error after log_error_after iterations.""" + error = OutputParserError("Test error") + messages: list[dict[str, str]] = [] + printer = MagicMock() + + handle_output_parser_exception( + e=error, + messages=messages, + iterations=4, + log_error_after=3, + printer=printer, + ) + + printer.print.assert_called_once() + call_args = printer.print.call_args + assert "Error parsing LLM output" in call_args.kwargs["content"] + assert call_args.kwargs["color"] == "red" + + def test_printer_does_not_log_before_log_error_after_iterations(self) -> None: + """Test that printer does not log before log_error_after iterations.""" + error = OutputParserError("Test error") + messages: list[dict[str, str]] = [] + printer = MagicMock() + + handle_output_parser_exception( + e=error, + messages=messages, + iterations=2, + log_error_after=3, + printer=printer, + ) + + printer.print.assert_not_called() + + def test_backward_compatibility_without_new_parameters(self) -> None: + """Test that the function works without the new optional parameters.""" + error = OutputParserError("Test error") + messages: list[dict[str, str]] = [] + + result = handle_output_parser_exception( + e=error, + messages=messages, + iterations=0, + ) + + assert isinstance(result, AgentAction) + assert len(messages) == 1