Add timing information to reasoning events to show duration in logs

Co-Authored-By: Joe Moura <joao@crewai.com>
This commit is contained in:
Devin AI
2025-05-27 09:41:37 +00:00
committed by João Moura
parent 1b18310cf7
commit 94c8412724
3 changed files with 41 additions and 7 deletions

View File

@@ -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

View File

@@ -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),
)

View File

@@ -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