Merge pull request #1758 from gooddata/feat/tool-call-latency-breakdown

Per-tool-call/reasoning-step latency breakdown (detail.latency_breakdown)

Author: Tomkess

packages/gooddata-eval/src/gooddata_eval/core/agentic/alert_skill.py

@@ -14,7 +14,7 @@
 from gooddata_eval.core.agentic._catalog import CatalogMetricAlert
 from gooddata_eval.core.chat.sse_client import ChatClient
 from gooddata_eval.core.config import ReasoningEffort
-from gooddata_eval.core.models import AgenticEvalOutcome, ToolCallEvent
+from gooddata_eval.core.models import AgenticEvalOutcome, ReasoningStepEvent, ToolCallEvent, build_latency_breakdown
 
 try:
     from openai import OpenAI as _OpenAI
@@ -345,6 +345,8 @@ class AlertRunResult:
     actual_alert_arguments: dict
     reasoning_steps: list[str] = field(default_factory=list)
     response_id: str | None = None
+    tool_call_events: list[ToolCallEvent] = field(default_factory=list)
+    reasoning_step_events: list[ReasoningStepEvent] = field(default_factory=list)
 
 
 @dataclass
@@ -495,6 +497,11 @@ def _run_once(conv_id: str) -> AlertRunResult:
             tool_called = False
             reasoning_steps: list[str] = []
             response_id: str | None = None
+            all_tool_call_events: list[ToolCallEvent] = []
+            all_reasoning_step_events: list[ReasoningStepEvent] = []
+            turn_offset = 0.0  # each turn's call_ts/ts restarts near 0 -- shift by prior turns' wall time
+            tool_index_offset = 0
+            reasoning_index_offset = 0
             # conversation_history stores prior turns for GPT-4o context.
             # Roles follow GPT-4o's perspective: "assistant"=agent text, "user"=sim-user reply.
             conversation_history: list = []
@@ -504,6 +511,21 @@ def _run_once(conv_id: str) -> AlertRunResult:
                 chat_result = client.send_message(conv_id, current_question)
                 reasoning_steps.extend(chat_result.reasoning_steps or [])
                 response_id = chat_result.response_id or response_id
+                for tc in chat_result.tool_call_events or []:
+                    if tc.call_ts is not None:
+                        tc.call_ts += turn_offset
+                    if tc.result_ts is not None:
+                        tc.result_ts += turn_offset
+                    if tc.index is not None:
+                        tc.index += tool_index_offset
+                for rs in chat_result.reasoning_step_events or []:
+                    rs.ts += turn_offset
+                    rs.index += reasoning_index_offset
+                all_tool_call_events.extend(chat_result.tool_call_events or [])
+                all_reasoning_step_events.extend(chat_result.reasoning_step_events or [])
+                tool_index_offset += len(chat_result.tool_call_events or [])
+                reasoning_index_offset += len(chat_result.reasoning_step_events or [])
+                turn_offset += chat_result.turn_wall_clock_sec or 0.0
                 alert_id, actual_args, tool_called = _extract_alert_call(chat_result.tool_call_events or [])
                 if tool_called:
                     alert_id_to_delete = alert_id
@@ -541,6 +563,8 @@ def _run_once(conv_id: str) -> AlertRunResult:
                 actual_alert_arguments=actual_args,
                 reasoning_steps=reasoning_steps,
                 response_id=response_id,
+                tool_call_events=all_tool_call_events,
+                reasoning_step_events=all_reasoning_step_events,
             )
         finally:
             if alert_id_to_delete:
@@ -717,6 +741,7 @@ def evaluate_agentic_alert_skill(
             "metric_correct": ev.metric_correct,
             "recipients_correct": ev.recipients_correct,
             "actual_alert_arguments": best.actual_alert_arguments,
+            "latency_breakdown": build_latency_breakdown(best.tool_call_events, best.reasoning_step_events),
         }
         raise exc
     best = summary.best
@@ -734,5 +759,6 @@ def evaluate_agentic_alert_skill(
             "metric_correct": ev.metric_correct,
             "recipients_correct": ev.recipients_correct,
             "actual_alert_arguments": best.actual_alert_arguments,
+            "latency_breakdown": build_latency_breakdown(best.tool_call_events, best.reasoning_step_events),
         },
     )

packages/gooddata-eval/src/gooddata_eval/core/agentic/conversation.py

@@ -15,7 +15,13 @@
 from gooddata_eval.core.agentic.metric_skill import _delete_metric, _extract_created_metric_ids, _extract_metric_result
 from gooddata_eval.core.chat.sse_client import ChatClient
 from gooddata_eval.core.config import ReasoningEffort
-from gooddata_eval.core.models import AgenticEvalOutcome, ChatResult, ToolCallEvent
+from gooddata_eval.core.models import (
+    AgenticEvalOutcome,
+    ChatResult,
+    ReasoningStepEvent,
+    ToolCallEvent,
+    build_latency_breakdown,
+)
 from gooddata_eval.core.scoring import (
     check_filters,
     check_viz_type,
@@ -254,6 +260,8 @@ class ConversationResult:
     total_clarification_turns: int
     reasoning_steps: list[str] = field(default_factory=list)
     response_id: str | None = None
+    tool_call_events: list[ToolCallEvent] = field(default_factory=list)
+    reasoning_step_events: list[ReasoningStepEvent] = field(default_factory=list)
 
 
 def run_agentic_conversation(
@@ -287,6 +295,14 @@ def run_agentic_conversation(
     created_metric_ids: list[str] = []
     reasoning_steps: list[str] = []
     response_id: str | None = None
+    conversation_tool_call_events: list[ToolCallEvent] = []
+    conversation_reasoning_step_events: list[ReasoningStepEvent] = []
+    # Every send_message() call (across every logical turn AND every clarification
+    # sub-turn within it) restarts call_ts/ts near 0 -- these run across the whole
+    # conversation, not reset per logical turn, so every one of those calls shifts them.
+    turn_offset = 0.0
+    tool_index_offset = 0
+    reasoning_index_offset = 0
 
     try:
         if initial_conversation_id is not None:
@@ -322,7 +338,22 @@ def run_agentic_conversation(
             for _iter in range(max_clarification_turns + 1):
                 chat_result = client.send_message(conversation_id, current_message)
                 final_result = chat_result
+                for tc in chat_result.tool_call_events or []:
+                    if tc.call_ts is not None:
+                        tc.call_ts += turn_offset
+                    if tc.result_ts is not None:
+                        tc.result_ts += turn_offset
+                    if tc.index is not None:
+                        tc.index += tool_index_offset
+                for rs in chat_result.reasoning_step_events or []:
+                    rs.ts += turn_offset
+                    rs.index += reasoning_index_offset
                 all_tool_calls.extend(chat_result.tool_call_events or [])
+                conversation_tool_call_events.extend(chat_result.tool_call_events or [])
+                conversation_reasoning_step_events.extend(chat_result.reasoning_step_events or [])
+                tool_index_offset += len(chat_result.tool_call_events or [])
+                reasoning_index_offset += len(chat_result.reasoning_step_events or [])
+                turn_offset += chat_result.turn_wall_clock_sec or 0.0
                 reasoning_steps.extend(chat_result.reasoning_steps or [])
                 response_id = chat_result.response_id or response_id
 
@@ -390,6 +421,8 @@ def run_agentic_conversation(
         total_clarification_turns=total_clarification_turns,
         reasoning_steps=reasoning_steps,
         response_id=response_id,
+        tool_call_events=conversation_tool_call_events,
+        reasoning_step_events=conversation_reasoning_step_events,
     )
 
 
@@ -408,6 +441,7 @@ def _conversation_detail(result: ConversationResult) -> dict:
             }
             for tr in result.turn_results
         ],
+        "latency_breakdown": build_latency_breakdown(result.tool_call_events, result.reasoning_step_events),
     }
 
 

packages/gooddata-eval/src/gooddata_eval/core/agentic/guardrail.py

@@ -8,7 +8,7 @@
 from gooddata_eval.core.chat.sse_client import ChatClient
 from gooddata_eval.core.config import ReasoningEffort
 from gooddata_eval.core.evaluators._llm_judge import LLMJudge
-from gooddata_eval.core.models import AgenticEvalOutcome
+from gooddata_eval.core.models import AgenticEvalOutcome, ReasoningStepEvent, ToolCallEvent, build_latency_breakdown
 
 _DEFAULT_K = 1
 
@@ -52,6 +52,8 @@ class GuardrailResult:
     reasoning: str
     reasoning_steps: list[str] = field(default_factory=list)
     response_id: str | None = None
+    tool_call_events: list[ToolCallEvent] = field(default_factory=list)
+    reasoning_step_events: list[ReasoningStepEvent] = field(default_factory=list)
 
 
 @dataclass
@@ -100,6 +102,8 @@ def run_agentic_guardrail(
                     reasoning=reasoning,
                     reasoning_steps=list(chat_result.reasoning_steps or []),
                     response_id=chat_result.response_id,
+                    tool_call_events=list(chat_result.tool_call_events or []),
+                    reasoning_step_events=list(chat_result.reasoning_step_events or []),
                 )
             )
         finally:
@@ -124,6 +128,8 @@ def run_agentic_guardrail(
                         reasoning=reasoning,
                         reasoning_steps=list(chat_result.reasoning_steps or []),
                         response_id=chat_result.response_id,
+                        tool_call_events=list(chat_result.tool_call_events or []),
+                        reasoning_step_events=list(chat_result.reasoning_step_events or []),
                     )
                 )
             finally:
@@ -245,6 +251,7 @@ def evaluate_agentic_guardrail(
             "judge_passed": best.passed,
             "judge_reasoning": best.reasoning,
             "actual_output": best.actual_output,
+            "latency_breakdown": build_latency_breakdown(best.tool_call_events, best.reasoning_step_events),
         }
         raise exc
     best = summary.best
@@ -256,5 +263,6 @@ def evaluate_agentic_guardrail(
             "judge_passed": best.passed,
             "judge_reasoning": best.reasoning,
             "actual_output": best.actual_output,
+            "latency_breakdown": build_latency_breakdown(best.tool_call_events, best.reasoning_step_events),
         },
     )

packages/gooddata-eval/src/gooddata_eval/core/agentic/metric_skill.py

@@ -12,7 +12,7 @@
 
 from gooddata_eval.core.chat.sse_client import ChatClient
 from gooddata_eval.core.config import ReasoningEffort
-from gooddata_eval.core.models import AgenticEvalOutcome, ToolCallEvent
+from gooddata_eval.core.models import AgenticEvalOutcome, ReasoningStepEvent, ToolCallEvent, build_latency_breakdown
 
 try:
     from openai import OpenAI as _OpenAI
@@ -150,6 +150,8 @@ class MetricRunResult:
     total_turns: float
     reasoning_steps: list[str] = field(default_factory=list)
     response_id: str | None = None
+    tool_call_events: list[ToolCallEvent] = field(default_factory=list)
+    reasoning_step_events: list[ReasoningStepEvent] = field(default_factory=list)
 
 
 @dataclass
@@ -239,13 +241,33 @@ def _execute_single_metric_run(
     current_question = question
     reasoning_steps: list[str] = []
     response_id: str | None = None
+    all_tool_call_events: list[ToolCallEvent] = []
+    all_reasoning_step_events: list[ReasoningStepEvent] = []
+    turn_offset = 0.0  # each turn's call_ts/ts restarts near 0 -- shift by prior turns' wall time
+    tool_index_offset = 0
+    reasoning_index_offset = 0
 
     try:
         for _iteration in range(max_iterations):
             turns += 1
             chat_result = client.send_message(conversation_id, current_question)
             reasoning_steps.extend(chat_result.reasoning_steps or [])
             response_id = chat_result.response_id or response_id
+            for tc in chat_result.tool_call_events or []:
+                if tc.call_ts is not None:
+                    tc.call_ts += turn_offset
+                if tc.result_ts is not None:
+                    tc.result_ts += turn_offset
+                if tc.index is not None:
+                    tc.index += tool_index_offset
+            for rs in chat_result.reasoning_step_events or []:
+                rs.ts += turn_offset
+                rs.index += reasoning_index_offset
+            all_tool_call_events.extend(chat_result.tool_call_events or [])
+            all_reasoning_step_events.extend(chat_result.reasoning_step_events or [])
+            tool_index_offset += len(chat_result.tool_call_events or [])
+            reasoning_index_offset += len(chat_result.reasoning_step_events or [])
+            turn_offset += chat_result.turn_wall_clock_sec or 0.0
             for metric_id in _extract_created_metric_ids(chat_result.tool_call_events or []):
                 if metric_id not in created_metric_ids:
                     created_metric_ids.append(metric_id)
@@ -276,6 +298,8 @@ def _execute_single_metric_run(
             total_turns=float(turns),
             reasoning_steps=reasoning_steps,
             response_id=response_id,
+            tool_call_events=all_tool_call_events,
+            reasoning_step_events=all_reasoning_step_events,
         )
     finally:
         for metric_id in created_metric_ids:
@@ -457,6 +481,7 @@ def evaluate_agentic_metric_skill(
             "maql_correct": best.maql_correct,
             "expected_maql_candidates": [c.get("maql", "") for c in expected_outputs_list],
             "actual_maql": best.actual_maql,
+            "latency_breakdown": build_latency_breakdown(best.tool_call_events, best.reasoning_step_events),
         }
         raise exc
     best = summary.best
@@ -470,5 +495,6 @@ def evaluate_agentic_metric_skill(
             "maql_correct": best.maql_correct,
             "expected_maql_candidates": [c.get("maql", "") for c in expected_outputs_list],
             "actual_maql": best.actual_maql,
+            "latency_breakdown": build_latency_breakdown(best.tool_call_events, best.reasoning_step_events),
         },
     )

packages/gooddata-eval/src/gooddata_eval/core/agentic/visualization.py

@@ -18,7 +18,13 @@
     _evaluate_against_candidates,
     evaluation_result_detail,
 )
-from gooddata_eval.core.models import AgenticEvalOutcome, CreatedVisualization, ToolCallEvent
+from gooddata_eval.core.models import (
+    AgenticEvalOutcome,
+    CreatedVisualization,
+    ReasoningStepEvent,
+    ToolCallEvent,
+    build_latency_breakdown,
+)
 from gooddata_eval.core.scoring import get_dimension_uri_set, get_metric_uri_set, uri_to_display_name
 
 _DEFAULT_K = 2
@@ -37,6 +43,8 @@ class RunResult:
     total_steps: float
     reasoning_steps: list[str] = field(default_factory=list)
     response_id: str | None = None
+    tool_call_events: list[ToolCallEvent] = field(default_factory=list)
+    reasoning_step_events: list[ReasoningStepEvent] = field(default_factory=list)
 
 
 @dataclass
@@ -161,18 +169,36 @@ def _execute_single_run(
     total_turns = 0.0
     total_steps = 0.0
     all_tool_call_events: list[ToolCallEvent] = []
+    all_reasoning_step_events: list[ReasoningStepEvent] = []
     reasoning_steps: list[str] = []
     response_id: str | None = None
+    turn_offset = 0.0  # each turn's call_ts/ts restarts near 0 -- shift by prior turns' wall time
+    reasoning_index_offset = 0  # ditto for ReasoningStepEvent.index, which also restarts per turn
+    tool_index_offset = 0  # ditto for ToolCallEvent.index
     simulated_response_guide = expected_outputs[0]  # primary candidate guides the simulated user
 
     current_result = client.send_message(conversation_id, question)
 
     for iteration in range(max_iterations):
         total_turns += 1.0
         total_steps += float(current_result.reasoning_step_count)
+        for tc in current_result.tool_call_events:
+            if tc.call_ts is not None:
+                tc.call_ts += turn_offset
+            if tc.result_ts is not None:
+                tc.result_ts += turn_offset
+            if tc.index is not None:
+                tc.index += tool_index_offset
+        for rs in current_result.reasoning_step_events:
+            rs.ts += turn_offset
+            rs.index += reasoning_index_offset
         all_tool_call_events.extend(current_result.tool_call_events)
+        all_reasoning_step_events.extend(current_result.reasoning_step_events)
+        tool_index_offset += len(current_result.tool_call_events)
+        reasoning_index_offset += len(current_result.reasoning_step_events)
         reasoning_steps.extend(current_result.reasoning_steps or [])
         response_id = current_result.response_id or response_id
+        turn_offset += current_result.turn_wall_clock_sec or 0.0
 
         viz_produced = bool(current_result.created_visualizations and current_result.created_visualizations.objects)
         if viz_produced:
@@ -201,6 +227,8 @@ def _execute_single_run(
         total_steps=total_steps,
         reasoning_steps=reasoning_steps,
         response_id=response_id,
+        tool_call_events=all_tool_call_events,
+        reasoning_step_events=all_reasoning_step_events,
     )
 
 
@@ -434,12 +462,18 @@ def evaluate_agentic_visualization(
         exc.reasoning_steps = best.reasoning_steps
         exc.conversation_id = best.conversation_id
         exc.response_id = best.response_id
-        exc.detail = evaluation_result_detail(ev)
+        exc.detail = {
+            **evaluation_result_detail(ev),
+            "latency_breakdown": build_latency_breakdown(best.tool_call_events, best.reasoning_step_events),
+        }
         raise exc
     best = summary.best
     return AgenticEvalOutcome(
         reasoning_steps=best.reasoning_steps,
         conversation_id=best.conversation_id,
         response_id=best.response_id,
-        detail=evaluation_result_detail(best.eval_result),
+        detail={
+            **evaluation_result_detail(best.eval_result),
+            "latency_breakdown": build_latency_breakdown(best.tool_call_events, best.reasoning_step_events),
+        },
     )