Python telemetry (#223)

* initial work on telemetry

* moved tool operation const

* missing quotes

* working otel with samples

* updated readme and other assets

* added tests

* added tests

* small updates

* updated genaiattributes docs

* updated tests

* additional warning

* cleanup of tests

python/packages/main/agent_framework/_tools.py

@@ -3,10 +3,19 @@
 import inspect
 from collections.abc import Awaitable, Callable
 from functools import wraps
+from time import perf_counter
 from typing import Any, Generic, Protocol, TypeVar, runtime_checkable
 
+from opentelemetry import metrics, trace
 from pydantic import BaseModel, create_model
 
+from ._logging import get_logger
+from .telemetry import GenAIAttributes, start_as_current_span
+
+tracer: trace.Tracer = trace.get_tracer("agent_framework")
+meter: metrics.Meter = metrics.get_meter_provider().get_meter("agent_framework")
+logger = get_logger()
+
 __all__ = ["AIFunction", "AITool", "HostedCodeInterpreterTool", "ai_function"]
 
 
@@ -65,6 +74,11 @@ class AIFunction(AITool, Generic[ArgsT, ReturnT]):
         self.input_model = input_model
         self.additional_properties: dict[str, Any] | None = kwargs
         self._func = func
+        self.invocation_duration_histogram = meter.create_histogram(
+            "agent_framework.function.invocation.duration",
+            unit="s",
+            description="Measures the duration of a function's execution",
+        )
 
     def parameters(self) -> dict[str, Any]:
         """Return the parameter json schemas of the input model."""
@@ -89,14 +103,38 @@ class AIFunction(AITool, Generic[ArgsT, ReturnT]):
             arguments: A Pydantic model instance containing the arguments for the function.
             kwargs: keyword arguments to pass to the function, will not be used if `args` is provided.
         """
+        tool_call_id = kwargs.pop("tool_call_id", None)
         if arguments is not None:
             if not isinstance(arguments, self.input_model):
                 raise TypeError(f"Expected {self.input_model.__name__}, got {type(arguments).__name__}")
             kwargs = arguments.model_dump(exclude_none=True)
-        res = self.__call__(**kwargs)
-        if inspect.isawaitable(res):
-            return await res
-        return res
+        logger.info(f"Function name: {self.name}")
+        logger.debug(f"Function arguments: {kwargs}")
+        with start_as_current_span(
+            tracer, self, metadata={"tool_call_id": tool_call_id, "kwargs": kwargs}
+        ) as current_span:
+            attributes: dict[str, Any] = {
+                GenAIAttributes.MEASUREMENT_FUNCTION_TAG_NAME.value: self.name,
+                GenAIAttributes.TOOL_CALL_ID.value: tool_call_id,
+            }
+            starting_time_stamp = perf_counter()
+            try:
+                res = self.__call__(**kwargs)
+                result = await res if inspect.isawaitable(res) else res
+                logger.info(f"Function {self.name} succeeded.")
+                logger.debug(f"Function result: {result or 'None'}")
+                return result  # type: ignore[reportReturnType]
+            except Exception as exception:
+                attributes[GenAIAttributes.ERROR_TYPE.value] = type(exception).__name__
+                current_span.record_exception(exception)
+                current_span.set_attribute(GenAIAttributes.ERROR_TYPE.value, type(exception).__name__)
+                current_span.set_status(trace.StatusCode.ERROR, description=str(exception))
+                logger.error(f"Function failed. Error: {exception}")
+                raise
+            finally:
+                duration = perf_counter() - starting_time_stamp
+                self.invocation_duration_histogram.record(duration, attributes=attributes)
+                logger.info("Function completed. Duration: %fs", duration)
 
 
 def ai_function(