refactor(telemetry): change agent and tool execution duration metrics from milliseconds to seconds

PiperOrigin-RevId: 931094668

Author: google-genai-bot

src/google/adk/telemetry/_instrumentation.py

@@ -40,7 +40,7 @@
 logger = logging.getLogger("google_adk." + __name__)
 
 
-def _get_elapsed_ms(
+def _get_elapsed_s(
     span: trace.Span | tracing.GenerateContentSpan | None,
     fallback_start: float,
 ) -> float:
@@ -54,20 +54,20 @@ def _get_elapsed_ms(
     fallback_start (float): Fallback start time in seconds (monotonic).
 
   Returns:
-    float: Elapsed duration in milliseconds.
+    float: Elapsed duration in seconds.
   """
   if span is None:
-    return (time.monotonic() - fallback_start) * 1000
+    return time.monotonic() - fallback_start
 
   span = span.span if hasattr(span, "span") else span
   start_ns = getattr(span, "start_time", None)
   end_ns = getattr(span, "end_time", None)
 
   if isinstance(start_ns, int) and isinstance(end_ns, int):
-    return (end_ns - start_ns) / 1e6  # Convert ns to ms
+    return (end_ns - start_ns) / 1e9  # Convert ns to s
 
   # Fallback if span times are missing
-  return (time.monotonic() - fallback_start) * 1000
+  return time.monotonic() - fallback_start
 
 
 @dataclasses.dataclass
@@ -93,15 +93,15 @@ def record_llm_response(
 
 def _record_agent_metrics(
     agent_name: str,
-    elapsed_ms: float,
+    elapsed_s: float,
     user_content: Any,
     events: Any,
     caught_error: Exception | None,
 ) -> None:
   try:
     _metrics.record_agent_invocation_duration(
         agent_name,
-        elapsed_ms,
+        elapsed_s,
         caught_error,
     )
     _metrics.record_agent_request_size(agent_name, user_content)
@@ -130,10 +130,9 @@ async def record_agent_invocation(
     caught_error = e
     raise
   finally:
-    elapsed_ms = _get_elapsed_ms(span, start_time)
     _record_agent_metrics(
         agent.name,
-        elapsed_ms,
+        _get_elapsed_s(span, start_time),
         getattr(ctx, "user_content", None),
         getattr(getattr(ctx, "session", None), "events", []),
         caught_error,
@@ -178,7 +177,7 @@ async def record_tool_execution(
       _metrics.record_tool_execution_duration(
           tool_name=tool.name,
           agent_name=agent.name,
-          elapsed_ms=_get_elapsed_ms(span, start_time),
+          elapsed_s=_get_elapsed_s(span, start_time),
           error=caught_error,
       )
     except Exception:  # pylint: disable=broad-exception-caught
@@ -206,13 +205,13 @@ async def record_inference_telemetry(
       yield tel_ctx
   finally:
     inference_error = sys.exc_info()[1]
-    elapsed_ms = _get_elapsed_ms(tel_ctx.span, start_time)
     agent = invocation_context.agent
+    elapsed_s = _get_elapsed_s(tel_ctx.span, start_time)
     try:
       if agent is not None and tracing._should_emit_native_telemetry(agent):
         _metrics.record_client_operation_duration(
             agent_name=agent.name,
-            elapsed_ms=elapsed_ms,
+            elapsed_s=elapsed_s,
             llm_request=llm_request,
             responses=tel_ctx.llm_responses,
             error=(

src/google/adk/telemetry/_metrics.py

@@ -43,12 +43,12 @@
 
 _agent_invocation_duration = meter.create_histogram(
     "gen_ai.agent.invocation.duration",
-    unit="ms",
+    unit="s",
     description="Duration of agent invocations.",
 )
 _tool_execution_duration = meter.create_histogram(
     "gen_ai.tool.execution.duration",
-    unit="ms",
+    unit="s",
     description="Duration of tool executions.",
 )
 _agent_request_size = meter.create_histogram(
@@ -74,14 +74,14 @@
 
 def record_agent_invocation_duration(
     agent_name: str,
-    elapsed_ms: float,
+    elapsed_s: float,
     error: Exception | None = None,
 ):
   """Records the duration of the agent invocation."""
   attrs = {gen_ai_attributes.GEN_AI_AGENT_NAME: agent_name}
   if error is not None:
     attrs[error_attributes.ERROR_TYPE] = type(error).__name__
-  _agent_invocation_duration.record(elapsed_ms, attributes=attrs)
+  _agent_invocation_duration.record(elapsed_s, attributes=attrs)
 
 
 def record_agent_request_size(
@@ -116,7 +116,7 @@ def record_agent_workflow_steps(agent_name: str, events: list[Event]):
 def record_tool_execution_duration(
     tool_name: str,
     agent_name: str,
-    elapsed_ms: float,
+    elapsed_s: float,
     error: Exception | None = None,
 ):
   """Records the duration of the tool execution."""
@@ -126,12 +126,12 @@ def record_tool_execution_duration(
   }
   if error is not None:
     attrs[error_attributes.ERROR_TYPE] = type(error).__name__
-  _tool_execution_duration.record(elapsed_ms, attributes=attrs)
+  _tool_execution_duration.record(elapsed_s, attributes=attrs)
 
 
 def record_client_operation_duration(
     agent_name: str,
-    elapsed_ms: float,
+    elapsed_s: float,
     llm_request: LlmRequest,
     responses: list[LlmResponse],
     error: Exception | None = None,
@@ -154,7 +154,7 @@ def record_client_operation_duration(
   if error is not None:
     attrs[error_attributes.ERROR_TYPE] = type(error).__name__
 
-  _client_operation_duration.record(elapsed_ms / 1000.0, attributes=attrs)
+  _client_operation_duration.record(elapsed_s, attributes=attrs)
 
 
 def record_client_token_usage(

tests/unittests/telemetry/test_instrumentation.py

@@ -22,65 +22,65 @@
 import pytest
 
 
-def test_get_elapsed_ms_span_none():
+def test_get_elapsed_s_span_none():
   """Tests fallback when span is None."""
   start_time = 10.0
   with mock.patch("time.monotonic", return_value=12.0):
-    elapsed = _instrumentation._get_elapsed_ms(None, start_time)
-  assert elapsed == 2000.0  # (12 - 10) * 1000
+    elapsed = _instrumentation._get_elapsed_s(None, start_time)
+  assert elapsed == 2.0  # 12 - 10
 
 
-def test_get_elapsed_ms_span_valid():
+def test_get_elapsed_s_span_valid():
   """Tests duration calculation with valid span times."""
   mock_span = mock.MagicMock(spec=trace.Span)
   mock_span.start_time = 1000000000  # 1s in ns
   mock_span.end_time = 2000000000  # 2s in ns
-  elapsed = _instrumentation._get_elapsed_ms(mock_span, time.monotonic())
-  assert elapsed == 1000.0  # (2 - 1) * 1000 ms
+  elapsed = _instrumentation._get_elapsed_s(mock_span, time.monotonic())
+  assert elapsed == 1.0  # (2 - 1) s
 
 
-def test_get_elapsed_ms_span_missing_start():
+def test_get_elapsed_s_span_missing_start():
   """Tests fallback when start_time is missing."""
   mock_span = mock.MagicMock(spec=trace.Span)
   del mock_span.start_time
   mock_span.end_time = 2000000000
   start_time = 10.0
   with mock.patch("time.monotonic", return_value=12.0):
-    elapsed = _instrumentation._get_elapsed_ms(mock_span, start_time)
-  assert elapsed == 2000.0
+    elapsed = _instrumentation._get_elapsed_s(mock_span, start_time)
+  assert elapsed == 2.0
 
 
-def test_get_elapsed_ms_span_missing_end():
+def test_get_elapsed_s_span_missing_end():
   """Tests fallback when end_time is missing."""
   mock_span = mock.MagicMock(spec=trace.Span)
   mock_span.start_time = 1000000000
   del mock_span.end_time
   start_time = 10.0
   with mock.patch("time.monotonic", return_value=12.0):
-    elapsed = _instrumentation._get_elapsed_ms(mock_span, start_time)
-  assert elapsed == 2000.0
+    elapsed = _instrumentation._get_elapsed_s(mock_span, start_time)
+  assert elapsed == 2.0
 
 
-def test_get_elapsed_ms_span_non_int_start():
+def test_get_elapsed_s_span_non_int_start():
   """Tests fallback when start_time is not an integer."""
   mock_span = mock.MagicMock(spec=trace.Span)
   mock_span.start_time = 1000000000.0
   mock_span.end_time = 2000000000
   start_time = 10.0
   with mock.patch("time.monotonic", return_value=12.0):
-    elapsed = _instrumentation._get_elapsed_ms(mock_span, start_time)
-  assert elapsed == 2000.0
+    elapsed = _instrumentation._get_elapsed_s(mock_span, start_time)
+  assert elapsed == 2.0
 
 
-def test_get_elapsed_ms_span_non_int_end():
+def test_get_elapsed_s_span_non_int_end():
   """Tests fallback when end_time is not an integer."""
   mock_span = mock.MagicMock(spec=trace.Span)
   mock_span.start_time = 1000000000
   mock_span.end_time = 2000000000.0
   start_time = 10.0
   with mock.patch("time.monotonic", return_value=12.0):
-    elapsed = _instrumentation._get_elapsed_ms(mock_span, start_time)
-  assert elapsed == 2000.0
+    elapsed = _instrumentation._get_elapsed_s(mock_span, start_time)
+  assert elapsed == 2.0
 
 
 @pytest.mark.asyncio
@@ -111,7 +111,7 @@ async def test_record_agent_invocation_tolerates_minimal_context():
 
   mock_record.assert_called_once()
   call_args = mock_record.call_args
-  # positional: (agent_name, elapsed_ms, user_content, events, caught_error)
+  # positional: (agent_name, elapsed_s, user_content, events, caught_error)
   assert call_args.args[0] == "test_agent"
   assert call_args.args[2] is None  # user_content default
   assert call_args.args[3] == []  # events default

tests/unittests/telemetry/test_metrics.py

@@ -107,12 +107,12 @@ def test_record_agent_invocation_duration(mock_meter_setup):
   """Tests record_agent_invocation_duration records correctly."""
   _metrics.record_agent_invocation_duration(
       "test_agent",
-      1000.0,
+      1.0,
   )
   agent_duration_hist = mock_meter_setup["agent_duration"]
   agent_duration_hist.record.assert_called_once()
   args, kwargs = agent_duration_hist.record.call_args
-  assert args[0] == 1000.0
+  assert args[0] == 1.0
   want_attributes = {"gen_ai.agent.name": "test_agent"}
   assert kwargs["attributes"] == want_attributes
 
@@ -122,7 +122,7 @@ def test_record_agent_invocation_duration_with_error(mock_meter_setup):
   test_error = ValueError("agent failed")
   _metrics.record_agent_invocation_duration(
       "test_agent",
-      1000.0,
+      1.0,
       error=test_error,
   )
   agent_duration_hist = mock_meter_setup["agent_duration"]
@@ -170,12 +170,12 @@ def test_record_tool_execution_duration(mock_meter_setup):
   _metrics.record_tool_execution_duration(
       "test_tool",
       "test_agent",
-      500.0,
+      0.5,
   )
   tool_duration_hist = mock_meter_setup["tool_duration"]
   tool_duration_hist.record.assert_called_once()
   args, kwargs = tool_duration_hist.record.call_args
-  assert args[0] == 500.0
+  assert args[0] == 0.5
   want_attributes = {
       "gen_ai.agent.name": "test_agent",
       "gen_ai.tool.name": "test_tool",
@@ -189,7 +189,7 @@ def test_record_tool_execution_duration_with_error(mock_meter_setup):
   _metrics.record_tool_execution_duration(
       "test_tool",
       "test_agent",
-      500.0,
+      0.5,
       error=test_error,
   )
   tool_duration_hist = mock_meter_setup["tool_duration"]
@@ -260,7 +260,7 @@ def test_record_client_operation_duration(mock_meter_setup):
   )
   _metrics.record_client_operation_duration(
       agent_name="test_agent",
-      elapsed_ms=100.0,
+      elapsed_s=0.1,
       llm_request=llm_request,
       responses=[response],
   )