From 94c84127243cc6f3ddbc43bf2e212497534c545e Mon Sep 17 00:00:00 2001 From: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com> Date: Tue, 27 May 2025 09:41:37 +0000 Subject: [PATCH] Add timing information to reasoning events to show duration in logs Co-Authored-By: Joe Moura --- .../utilities/events/reasoning_events.py | 2 ++ .../events/utils/console_formatter.py | 32 +++++++++++++++---- src/crewai/utilities/reasoning_handler.py | 14 +++++++- 3 files changed, 41 insertions(+), 7 deletions(-) diff --git a/src/crewai/utilities/events/reasoning_events.py b/src/crewai/utilities/events/reasoning_events.py index b673f3e71..51f9effac 100644 --- a/src/crewai/utilities/events/reasoning_events.py +++ b/src/crewai/utilities/events/reasoning_events.py @@ -19,6 +19,7 @@ class AgentReasoningCompletedEvent(BaseEvent): plan: str ready: bool attempt: int = 1 + duration_seconds: float = 0.0 # Time taken for reasoning in seconds class AgentReasoningFailedEvent(BaseEvent): @@ -50,3 +51,4 @@ class AgentMidExecutionReasoningCompletedEvent(BaseEvent): current_step: int updated_plan: str reasoning_trigger: str + duration_seconds: float = 0.0 # Time taken for reasoning in seconds diff --git a/src/crewai/utilities/events/utils/console_formatter.py b/src/crewai/utilities/events/utils/console_formatter.py index bcf12caaf..b94b318fa 100644 --- a/src/crewai/utilities/events/utils/console_formatter.py +++ b/src/crewai/utilities/events/utils/console_formatter.py @@ -1106,6 +1106,8 @@ class ConsoleFormatter: agent_branch: Optional[Tree], attempt: int, crew_tree: Optional[Tree], + current_step: Optional[int] = None, + reasoning_trigger: Optional[str] = None, ) -> Optional[Tree]: """Handle agent reasoning started (or refinement) event.""" if not self.verbose: @@ -1132,10 +1134,14 @@ class ConsoleFormatter: reasoning_branch = branch_to_use.add("") self.current_reasoning_branch = reasoning_branch - # Build label text depending on attempt - status_text = ( - f"Reasoning (Attempt {attempt})" if attempt > 1 else "Reasoning..." - ) + # Build label text depending on attempt and whether it's mid-execution + if current_step is not None: + trigger_text = f" ({reasoning_trigger})" if reasoning_trigger else "" + status_text = f"Mid-Execution Reasoning at step {current_step}{trigger_text}" + else: + status_text = ( + f"Reasoning (Attempt {attempt})" if attempt > 1 else "Reasoning..." + ) self.update_tree_label(reasoning_branch, "🧠", status_text, "blue") self.print(tree_to_use) @@ -1148,6 +1154,9 @@ class ConsoleFormatter: plan: str, ready: bool, crew_tree: Optional[Tree], + duration_seconds: float = 0.0, + current_step: Optional[int] = None, + reasoning_trigger: Optional[str] = None, ) -> None: """Handle agent reasoning completed event.""" if not self.verbose: @@ -1162,7 +1171,13 @@ class ConsoleFormatter: ) style = "green" if ready else "yellow" - status_text = "Reasoning Completed" if ready else "Reasoning Completed (Not Ready)" + duration_text = f" ({duration_seconds:.2f}s)" if duration_seconds > 0 else "" + + if current_step is not None: + trigger_text = f" ({reasoning_trigger})" if reasoning_trigger else "" + status_text = f"Mid-Execution Reasoning Completed at step {current_step}{trigger_text}{duration_text}" + else: + status_text = f"Reasoning Completed{duration_text}" if ready else f"Reasoning Completed (Not Ready){duration_text}" if reasoning_branch is not None: self.update_tree_label(reasoning_branch, "✅", status_text, style) @@ -1172,9 +1187,14 @@ class ConsoleFormatter: # Show plan in a panel (trim very long plans) if plan: + if current_step is not None: + title = f"🧠 Mid-Execution Reasoning Plan (Step {current_step}){duration_text}" + else: + title = f"🧠 Reasoning Plan{duration_text}" + plan_panel = Panel( Text(plan, style="white"), - title="🧠 Reasoning Plan", + title=title, border_style=style, padding=(1, 2), ) diff --git a/src/crewai/utilities/reasoning_handler.py b/src/crewai/utilities/reasoning_handler.py index 19135ee96..dd58a75eb 100644 --- a/src/crewai/utilities/reasoning_handler.py +++ b/src/crewai/utilities/reasoning_handler.py @@ -55,6 +55,9 @@ class AgentReasoning: Returns: AgentReasoningOutput: The output of the agent reasoning process. """ + import time + start_time = time.time() + # Emit a reasoning started event (attempt 1) try: crewai_event_bus.emit( @@ -71,6 +74,8 @@ class AgentReasoning: try: output = self.__handle_agent_reasoning() + + duration_seconds = time.time() - start_time # Emit reasoning completed event try: @@ -82,6 +87,7 @@ class AgentReasoning: plan=output.plan.plan, ready=output.plan.ready, attempt=1, + duration_seconds=duration_seconds, ), ) except Exception: @@ -425,6 +431,9 @@ class AgentReasoning: Returns: AgentReasoningOutput: Updated reasoning plan based on current context """ + import time + start_time = time.time() + from crewai.utilities.events.reasoning_events import AgentMidExecutionReasoningStartedEvent self._emit_reasoning_event( @@ -436,6 +445,8 @@ class AgentReasoning: output = self.__handle_mid_execution_reasoning( current_steps, tools_used, current_progress, iteration_messages ) + + duration_seconds = time.time() - start_time # Emit completed event from crewai.utilities.events.reasoning_events import AgentMidExecutionReasoningCompletedEvent @@ -443,7 +454,8 @@ class AgentReasoning: self._emit_reasoning_event( AgentMidExecutionReasoningCompletedEvent, current_step=current_steps, - updated_plan=output.plan.plan + updated_plan=output.plan.plan, + duration_seconds=duration_seconds ) return output