From cbdc94218f67eef6edcc5a2ac6c0e0b8c9a4ed19 Mon Sep 17 00:00:00 2001 From: Rodrigo Brandao Date: Tue, 14 Apr 2026 17:10:17 -0700 Subject: [PATCH 1/5] More improvements to OTEL for consistency with docs --- .../activity/suggested_actions.py | 2 +- .../core/app/oauth/telemetry/constants.py | 4 +- .../hosting/core/app/telemetry/spans.py | 2 + .../core/authorization/telemetry/constants.py | 12 +- .../core/connector/client/connector_client.py | 34 +- .../core/connector/telemetry/constants.py | 20 +- .../telemetry/user_token_client_spans.py | 13 +- .../hosting/core/http/_http_adapter_base.py | 9 +- .../hosting/core/state/agent_state.py | 6 +- .../hosting/core/storage/telemetry/spans.py | 15 +- .../core/telemetry/adapter/constants.py | 1 + .../hosting/core/telemetry/adapter/spans.py | 24 ++ .../hosting/core/telemetry/attributes.py | 1 + .../core/telemetry/core/_agents_telemetry.py | 27 +- .../core/telemetry/turn_context/spans.py | 2 +- .../hosting/core/turn_context.py | 74 ++-- .../hosting_core/telemetry/test_app_spans.py | 17 + .../telemetry/test_connector_spans.py | 373 ++++++++++++++++++ .../telemetry/test_http_adapter_telemetry.py | 327 +++++++++++++++ .../telemetry/test_simple_span_wrapper.py | 10 - .../telemetry/test_storage_spans.py | 55 +++ .../telemetry/test_turn_context_spans.py | 10 +- .../telemetry/test_user_token_client_spans.py | 311 +++++++++++++++ 23 files changed, 1218 insertions(+), 131 deletions(-) create mode 100644 tests/hosting_core/telemetry/test_connector_spans.py create mode 100644 tests/hosting_core/telemetry/test_http_adapter_telemetry.py create mode 100644 tests/hosting_core/telemetry/test_user_token_client_spans.py diff --git a/libraries/microsoft-agents-activity/microsoft_agents/activity/suggested_actions.py b/libraries/microsoft-agents-activity/microsoft_agents/activity/suggested_actions.py index 1e723d2d..5d1c4de1 100644 --- a/libraries/microsoft-agents-activity/microsoft_agents/activity/suggested_actions.py +++ b/libraries/microsoft-agents-activity/microsoft_agents/activity/suggested_actions.py @@ -17,5 +17,5 @@ class SuggestedActions(AgentsModel): :type actions: list[~microsoft_agents.activity.CardAction] """ - to: list[NonEmptyString] + to: list[NonEmptyString] = [] actions: list[CardAction] diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/oauth/telemetry/constants.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/oauth/telemetry/constants.py index 0897443b..1961ac72 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/oauth/telemetry/constants.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/oauth/telemetry/constants.py @@ -3,5 +3,5 @@ AGENTIC_TOKEN = "agents.authorization.agentic_token" AZURE_BOT_TOKEN = "agents.authorization.azure_bot_token" -AZURE_BOT_SIGN_OUT = "agents.authorization.azure_bot_sign_out" -AZURE_BOT_SIGN_IN = "agents.authorization.azure_bot_sign_in" +AZURE_BOT_SIGN_OUT = "agents.authorization.azure_bot_signout" +AZURE_BOT_SIGN_IN = "agents.authorization.azure_bot_signin" diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/telemetry/spans.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/telemetry/spans.py index f48be961..5222b407 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/telemetry/spans.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/telemetry/spans.py @@ -35,12 +35,14 @@ def _callback(self, span: Span, duration: float, error: Exception | None) -> Non attributes.CONVERSATION_ID: get_conversation_id( self._turn_context.activity ), + attributes.SUCCESS: error is None, } if error is None: metrics.turn_count.add(1, attributes=attrs) metrics.turn_duration.record(duration, attributes=attrs) else: metrics.turn_error_count.add(1, attributes=attrs) + metrics.turn_duration.record(duration, attributes=attrs) def _get_attributes(self) -> AttributeMap: return { diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/authorization/telemetry/constants.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/authorization/telemetry/constants.py index 0bb23802..d782e389 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/authorization/telemetry/constants.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/authorization/telemetry/constants.py @@ -3,15 +3,15 @@ # Spans -SPAN_GET_ACCESS_TOKEN = "agents.auth.getAccessToken" -SPAN_ACQUIRE_TOKEN_ON_BEHALF_OF = "agents.auth.acquireTokenOnBehalfOf" -SPAN_GET_AGENTIC_INSTANCE_TOKEN = "agents.auth.getAgenticInstanceToken" -SPAN_GET_AGENTIC_USER_TOKEN = "agents.auth.getAgenticUserToken" +SPAN_GET_ACCESS_TOKEN = "agents.authentication.get_access_token" +SPAN_ACQUIRE_TOKEN_ON_BEHALF_OF = "agents.authentication.acquire_token_on_behalf_of" +SPAN_GET_AGENTIC_INSTANCE_TOKEN = "agents.authentication.get_agentic_instance_token" +SPAN_GET_AGENTIC_USER_TOKEN = "agents.authentication.get_agentic_user_token" # Metrics -METRIC_AUTH_TOKEN_REQUEST_DURATION = "agents.auth.token.request.duration" -METRIC_AUTH_TOKEN_REQUEST_COUNT = "agents.auth.token.request.count" +METRIC_AUTH_TOKEN_REQUEST_DURATION = "agents.auth.token.duration" +METRIC_AUTH_TOKEN_REQUEST_COUNT = "agents.auth.token.count" AUTH_METHOD_OBO = "obo" AUTH_METHOD_AGENTIC_INSTANCE = "agentic_instance" diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/client/connector_client.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/client/connector_client.py index 4230b4a1..5785b94e 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/client/connector_client.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/client/connector_client.py @@ -333,24 +333,24 @@ async def update_activity( conversation_id = self._normalize_conversation_id(conversation_id) url = f"v3/conversations/{conversation_id}/activities/{activity_id}" - logger.info( - "Updating activity: %s in conversation: %s. Activity type is %s", - activity_id, - conversation_id, - body.type, - ) - async with self.client.put( - url, - json=body.model_dump(by_alias=True, exclude_unset=True), - ) as response: - if response.status >= 300: - logger.error( - "Error updating activity: %s", response.status, stack_info=True - ) - response.raise_for_status() + logger.info( + "Updating activity: %s in conversation: %s. Activity type is %s", + activity_id, + conversation_id, + body.type, + ) + async with self.client.put( + url, + json=body.model_dump(by_alias=True, exclude_unset=True), + ) as response: + if response.status >= 300: + logger.error( + "Error updating activity: %s", response.status, stack_info=True + ) + response.raise_for_status() - data = await response.json() - return ResourceResponse.model_validate(data) + data = await response.json() + return ResourceResponse.model_validate(data) async def delete_activity(self, conversation_id: str, activity_id: str) -> None: """ diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/telemetry/constants.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/telemetry/constants.py index 3b3a9027..c716f1c7 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/telemetry/constants.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/telemetry/constants.py @@ -1,16 +1,16 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License. -SPAN_REPLY_TO_ACTIVITY = "agents.connector.replyToActivity" -SPAN_SEND_TO_CONVERSATION = "agents.connector.sendToConversation" -SPAN_UPDATE_ACTIVITY = "agents.connector.updateActivity" -SPAN_DELETE_ACTIVITY = "agents.connector.deleteActivity" -SPAN_CREATE_CONVERSATION = "agents.connector.createConversation" -SPAN_GET_CONVERSATIONS = "agents.connector.getConversations" -SPAN_GET_CONVERSATION_MEMBERS = "agents.connector.getConversationMembers" -SPAN_UPLOAD_ATTACHMENT = "agents.connector.uploadAttachment" -SPAN_GET_ATTACHMENT = "agents.connector.getAttachment" -SPAN_GET_ATTACHMENT_INFO = "agents.connector.getAttachmentInfo" +SPAN_REPLY_TO_ACTIVITY = "agents.connector.reply_to_activity" +SPAN_SEND_TO_CONVERSATION = "agents.connector.send_to_conversation" +SPAN_UPDATE_ACTIVITY = "agents.connector.update_activity" +SPAN_DELETE_ACTIVITY = "agents.connector.delete_activity" +SPAN_CREATE_CONVERSATION = "agents.connector.create_conversation" +SPAN_GET_CONVERSATIONS = "agents.connector.get_conversations" +SPAN_GET_CONVERSATION_MEMBERS = "agents.connector.get_conversation_members" +SPAN_UPLOAD_ATTACHMENT = "agents.connector.upload_attachment" +SPAN_GET_ATTACHMENT = "agents.connector.get_attachment" +SPAN_GET_ATTACHMENT_INFO = "agents.connector.get_attachment_info" SPAN_GET_USER_TOKEN = "agents.user_token_client.get_user_token" SPAN_SIGN_OUT = "agents.user_token_client.sign_out" diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/telemetry/user_token_client_spans.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/telemetry/user_token_client_spans.py index 9a6bdb62..196609fa 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/telemetry/user_token_client_spans.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/telemetry/user_token_client_spans.py @@ -38,14 +38,11 @@ def _get_attributes(self) -> dict[str, str]: NOTE: a dict is the annotated return type to allow child classes to add additional attributes. """ - attr_dict = {} - if self._connection_name is not None: - attr_dict[attributes.CONNECTION_NAME] = self._connection_name - if self._user_id is not None: - attr_dict[attributes.USER_ID] = self._user_id - if self._channel_id is not None: - attr_dict[attributes.ACTIVITY_CHANNEL_ID] = self._channel_id - return attr_dict + return { + attributes.CONNECTION_NAME: self._connection_name, + attributes.USER_ID: self._user_id, + attributes.ACTIVITY_CHANNEL_ID: self._channel_id, + } class GetUserToken(_UserTokenClientSpanWrapper): diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/http/_http_adapter_base.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/http/_http_adapter_base.py index 6de63fb1..b2fea448 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/http/_http_adapter_base.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/http/_http_adapter_base.py @@ -126,10 +126,11 @@ async def process_request( activity.type == "invoke" or activity.delivery_mode == DeliveryModes.expect_replies ): - # Invoke and ExpectReplies cannot be performed async - return HttpResponseFactory.json( - invoke_response.body, invoke_response.status - ) + with spans.AdapterWriteResponse(activity): + # Invoke and ExpectReplies cannot be performed async + return HttpResponseFactory.json( + invoke_response.body, invoke_response.status + ) return HttpResponseFactory.accepted() diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/state/agent_state.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/state/agent_state.py index 31b072ad..02df1a6c 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/state/agent_state.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/state/agent_state.py @@ -219,7 +219,11 @@ def get_value( if not value and default_value_factory is not None: # If the value is None and a factory is provided, call the factory to get a default value - return default_value_factory() + default = default_value_factory() + # Store the default value in the cache so modifications to it are tracked + if self._cached_state is not None: + self._cached_state.state[property_name] = default + return default if target_cls and value: # Attempt to deserialize the value if it is not None diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/storage/telemetry/spans.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/storage/telemetry/spans.py index 86ae7e90..764c9f7d 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/storage/telemetry/spans.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/storage/telemetry/spans.py @@ -15,9 +15,10 @@ class _StorageSpanWrapper(SimpleSpanWrapper): """Base SpanWrapper for spans related to storage operations. This is meant to be a base class for spans related to storage operations, such as retrieving or saving state, and can be used to share common functionality and attributes related to storage operations.""" - def __init__(self, span_name: str, *, key_count: int): + def __init__(self, span_name: str, operation_name: str, *, key_count: int): """Initializes the _StorageSpanWrapper span.""" super().__init__(span_name) + self._operation_name = operation_name self._key_count = key_count def _callback(self, span: Span, duration: float, error: Exception | None) -> None: @@ -25,13 +26,13 @@ def _callback(self, span: Span, duration: float, error: Exception | None) -> Non metrics.storage_operation_duration.record( duration, attributes={ - attributes.STORAGE_OPERATION: self._span_name, + attributes.STORAGE_OPERATION: self._operation_name, }, ) metrics.storage_operation_total.add( 1, attributes={ - attributes.STORAGE_OPERATION: self._span_name, + attributes.STORAGE_OPERATION: self._operation_name, }, ) @@ -42,6 +43,7 @@ def _get_attributes(self) -> dict[str, str | int]: """ return { attributes.KEY_COUNT: self._key_count, + attributes.STORAGE_OPERATION: self._operation_name, } @@ -50,7 +52,7 @@ class StorageRead(_StorageSpanWrapper): def __init__(self, key_count: int): """Initializes the StorageRead span.""" - super().__init__(constants.SPAN_STORAGE_READ, key_count=key_count) + super().__init__(constants.SPAN_STORAGE_READ, "read", key_count=key_count) class StorageWrite(_StorageSpanWrapper): @@ -58,12 +60,11 @@ class StorageWrite(_StorageSpanWrapper): def __init__(self, key_count: int): """Initializes the StorageWrite span.""" - super().__init__(constants.SPAN_STORAGE_WRITE, key_count=key_count) - + super().__init__(constants.SPAN_STORAGE_WRITE, "write", key_count=key_count) class StorageDelete(_StorageSpanWrapper): """Span for deleting from storage.""" def __init__(self, key_count: int): """Initializes the StorageDelete span.""" - super().__init__(constants.SPAN_STORAGE_DELETE, key_count=key_count) + super().__init__(constants.SPAN_STORAGE_DELETE, "delete", key_count=key_count) diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/constants.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/constants.py index 7ff5cfcd..43489e20 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/constants.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/constants.py @@ -8,6 +8,7 @@ SPAN_CONTINUE_CONVERSATION = "agents.adapter.continue_conversation" SPAN_CREATE_CONNECTOR_CLIENT = "agents.adapter.create_connector_client" SPAN_CREATE_USER_TOKEN_CLIENT = "agents.adapter.create_user_token_client" +SPAN_WRITE_RESPONSE = "agents.adapter.write_response" METRIC_ADAPTER_PROCESS_DURATION = "agents.adapter.process.duration" diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/spans.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/spans.py index 44c08aa8..4cba9ee8 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/spans.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/spans.py @@ -196,3 +196,27 @@ def _get_attributes(self) -> AttributeMap: attributes.AUTH_SCOPES: format_scopes(self._scopes), attributes.IS_AGENTIC: self._is_agentic_request, } + +class AdapterWriteResponse(SimpleSpanWrapper): + """Span for writing an InvokeResponse in the adapter. This captures the handling of expectReplies, invoke, and streaming""" + + def __init__(self, activity: Activity): + """Initializes the AdapterWriteResponse span.""" + super().__init__(constants.SPAN_WRITE_RESPONSE) + self._activity = activity + + def _callback(self, span: Span, duration: float, error: Exception | None) -> None: + metrics.activities_sent.add( + 1, + attributes={ + attributes.ACTIVITY_TYPE: self._activity.type, + attributes.ACTIVITY_CHANNEL_ID: self._activity.channel_id + or attributes.UNKNOWN, + }, + ) + + def _get_attributes(self) -> AttributeMap: + """Returns a dictionary of attributes to set on the span when it is started. This includes attributes related to the activities being sent.""" + return { + attributes.CONVERSATION_ID: get_conversation_id(self._activity), + } \ No newline at end of file diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/attributes.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/attributes.py index 379a443a..4b1adc9b 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/attributes.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/attributes.py @@ -39,6 +39,7 @@ SERVICE_URL = "service_url" STORAGE_OPERATION = "storage.operation" +SUCCESS = "success" TOKEN_SERVICE_ENDPOINT = "agents.token_service.endpoint" diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/core/_agents_telemetry.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/core/_agents_telemetry.py index 34c13ec4..a7cb7084 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/core/_agents_telemetry.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/core/_agents_telemetry.py @@ -40,27 +40,6 @@ def meter(self) -> Meter: """Returns the OpenTelemetry meter instance for recording metrics""" return self._meter - def _extract_attributes_from_context( - self, turn_context: TurnContextProtocol - ) -> dict: - """Helper method to extract common attributes from the TurnContext for span and metric recording""" - - # This can be expanded to extract common attributes for spans and metrics from the context - attributes = {} - attributes["activity.type"] = turn_context.activity.type - attributes["agent.is_agentic"] = turn_context.activity.is_agentic_request() - if turn_context.activity.from_property: - attributes["from.id"] = turn_context.activity.from_property.id - if turn_context.activity.recipient: - attributes["recipient.id"] = turn_context.activity.recipient.id - if turn_context.activity.conversation: - attributes["conversation.id"] = turn_context.activity.conversation.id - attributes["channel_id"] = turn_context.activity.channel_id - attributes["message.text.length"] = ( - len(turn_context.activity.text) if turn_context.activity.text else 0 - ) - return attributes - @contextmanager def start_as_current_span( self, @@ -74,7 +53,9 @@ def start_as_current_span( :return: An iterator that yields the started span, which will be ended when the context manager exits """ - with self._tracer.start_as_current_span(span_name) as span: + with self._tracer.start_as_current_span( + span_name, record_exception=False, set_status_on_exception=False + ) as span: start = time.time() exception: Exception | None = None @@ -92,7 +73,6 @@ def start_as_current_span( duration = (end - start) * 1000 # milliseconds if success: - span.add_event(f"{span_name} completed", {"duration_ms": duration}) span.set_status(trace.Status(trace.StatusCode.OK)) if callback: callback(span, duration, None) @@ -101,6 +81,7 @@ def start_as_current_span( callback(span, duration, exception) span.set_status(trace.Status(trace.StatusCode.ERROR)) + span.record_exception(exception) agents_telemetry = _AgentsTelemetry() diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/spans.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/spans.py index 8655731e..9fba48a2 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/spans.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/spans.py @@ -13,7 +13,7 @@ from . import constants -class TurnContextSendActivity(SimpleSpanWrapper): +class TurnContextSendActivities(SimpleSpanWrapper): """Span wrapper for sending an activity within a turn context.""" def __init__(self, turn_context: TurnContextProtocol): diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/turn_context.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/turn_context.py index 56165e93..9452aed9 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/turn_context.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/turn_context.py @@ -20,7 +20,7 @@ ) from microsoft_agents.activity.entity.entity_types import EntityTypes from microsoft_agents.hosting.core.authorization.claims_identity import ClaimsIdentity - +import microsoft_agents.hosting.core.telemetry.turn_context.spans as spans class TurnContext(TurnContextProtocol): # Same constant as in the BF Adapter, duplicating here to avoid circular dependency @@ -211,50 +211,52 @@ async def send_activities( # TODO: Check activity serialization ref = self.activity.get_conversation_reference() - def activity_validator(activity: Activity) -> Activity: - if not getattr(activity, "type", None): - activity.type = ActivityTypes.message - if activity.type != ActivityTypes.trace: + with spans.TurnContextSendActivities(self): + + def activity_validator(activity: Activity) -> Activity: + if not getattr(activity, "type", None): + activity.type = ActivityTypes.message + if activity.type != ActivityTypes.trace: + nonlocal sent_non_trace_activity + sent_non_trace_activity = True + if not activity.input_hint: + activity.input_hint = "acceptingInput" + activity.id = None + return activity + + output = [ + activity_validator( + TurnContext.apply_conversation_reference(deepcopy(act), ref) + ) + for act in activities + ] + + # send activities through adapter + async def logic(): nonlocal sent_non_trace_activity - sent_non_trace_activity = True - if not activity.input_hint: - activity.input_hint = "acceptingInput" - activity.id = None - return activity - - output = [ - activity_validator( - TurnContext.apply_conversation_reference(deepcopy(act), ref) - ) - for act in activities - ] - # send activities through adapter - async def logic(): - nonlocal sent_non_trace_activity + if self.activity.delivery_mode == DeliveryModes.expect_replies: + responses = [] + for activity in output: + self.buffered_reply_activities.append(activity) + # Ensure the TurnState has the InvokeResponseKey, since this activity + # is not being sent through the adapter, where it would be added to TurnState. + if activity.type == ActivityTypes.invoke_response: + self.turn_state[TurnContext._INVOKE_RESPONSE_KEY] = activity - if self.activity.delivery_mode == DeliveryModes.expect_replies: - responses = [] - for activity in output: - self.buffered_reply_activities.append(activity) - # Ensure the TurnState has the InvokeResponseKey, since this activity - # is not being sent through the adapter, where it would be added to TurnState. - if activity.type == ActivityTypes.invoke_response: - self.turn_state[TurnContext._INVOKE_RESPONSE_KEY] = activity + responses.append(ResourceResponse()) - responses.append(ResourceResponse()) + if sent_non_trace_activity: + self.responded = True + return responses + + responses = await self.adapter.send_activities(self, output) if sent_non_trace_activity: self.responded = True - return responses - responses = await self.adapter.send_activities(self, output) - if sent_non_trace_activity: - self.responded = True - return responses - - return await self._emit(self._on_send_activities, output, logic()) + return await self._emit(self._on_send_activities, output, logic()) async def update_activity(self, activity: Activity): """ diff --git a/tests/hosting_core/telemetry/test_app_spans.py b/tests/hosting_core/telemetry/test_app_spans.py index 8fe8ea71..14699fed 100644 --- a/tests/hosting_core/telemetry/test_app_spans.py +++ b/tests/hosting_core/telemetry/test_app_spans.py @@ -101,6 +101,23 @@ def test_app_on_turn_records_error_metric_on_exception( assert success_count == 0 +def test_app_on_turn_records_turn_duration_on_error( + test_exporter, test_metric_reader +): + """turn_duration is recorded on both success and error paths.""" + ctx = _make_context() + + try: + with AppOnTurn(ctx): + raise ValueError("boom") + except ValueError: + pass + + data = test_metric_reader.get_metrics_data() + duration_count = sum_hist_count(find_metric(data, constants.METRIC_TURN_DURATION)) + assert duration_count == 1 + + def test_app_on_turn_share(test_exporter): ctx = _make_context() diff --git a/tests/hosting_core/telemetry/test_connector_spans.py b/tests/hosting_core/telemetry/test_connector_spans.py new file mode 100644 index 00000000..4121498d --- /dev/null +++ b/tests/hosting_core/telemetry/test_connector_spans.py @@ -0,0 +1,373 @@ +# Copyright (c) Microsoft Corporation. All rights reserved. +# Licensed under the MIT License. + +import pytest +from opentelemetry import trace + +from microsoft_agents.hosting.core.telemetry import attributes +from microsoft_agents.hosting.core.connector.telemetry.connector_spans import ( + ConnectorReplyToActivity, + ConnectorSendToConversation, + ConnectorUpdateActivity, + ConnectorDeleteActivity, + ConnectorCreateConversation, + ConnectorGetConversations, + ConnectorGetConversationMembers, + ConnectorUploadAttachment, + ConnectorGetAttachmentInfo, + ConnectorGetAttachment, +) +from microsoft_agents.hosting.core.connector.telemetry import constants + +from tests._common.fixtures.telemetry import ( # unused imports are needed for fixtures + test_telemetry, + test_exporter, + test_metric_reader, +) +from tests._common.telemetry_utils import find_metric, sum_counter, sum_hist_count + + +# ---- ConnectorReplyToActivity ---- + + +def test_connector_reply_to_activity_creates_span(test_exporter): + with ConnectorReplyToActivity("conv-1", "act-1"): + pass + + spans = test_exporter.get_finished_spans() + assert len(spans) == 1 + assert spans[0].name == constants.SPAN_REPLY_TO_ACTIVITY + + +def test_connector_reply_to_activity_span_attributes(test_exporter): + with ConnectorReplyToActivity("conv-abc", "act-xyz"): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.CONVERSATION_ID] == "conv-abc" + assert span.attributes[attributes.ACTIVITY_ID] == "act-xyz" + + +def test_connector_reply_to_activity_records_metrics(test_exporter, test_metric_reader): + with ConnectorReplyToActivity("conv-1", "act-1") as span: + span.share(http_method="POST", status_code=200) + + data = test_metric_reader.get_metrics_data() + count = sum_counter(find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT)) + assert count == 1 + duration = sum_hist_count( + find_metric(data, constants.METRIC_CONNECTOR_REQUEST_DURATION) + ) + assert duration == 1 + + +def test_connector_reply_to_activity_metrics_include_http_attrs( + test_exporter, test_metric_reader +): + with ConnectorReplyToActivity("conv-1", "act-1") as span: + span.share(http_method="POST", status_code=200) + + data = test_metric_reader.get_metrics_data() + count = sum_counter( + find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT), + attribute_filter={ + attributes.HTTP_METHOD: "POST", + attributes.HTTP_STATUS_CODE: 200, + }, + ) + assert count == 1 + + +def test_connector_span_without_share_omits_http_attrs_from_metrics( + test_exporter, test_metric_reader +): + """When share() is never called, http_method and status_code are absent from metrics.""" + with ConnectorReplyToActivity("conv-1", "act-1"): + pass + + data = test_metric_reader.get_metrics_data() + # Total count still recorded + total = sum_counter(find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT)) + assert total == 1 + # But filtering by http_method finds nothing + with_method = sum_counter( + find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT), + attribute_filter={attributes.HTTP_METHOD: "POST"}, + ) + assert with_method == 0 + + +def test_connector_span_operation_attribute_is_span_name( + test_exporter, test_metric_reader +): + """Metrics include OPERATION set to the span name.""" + with ConnectorReplyToActivity("conv-1", "act-1") as span: + span.share(http_method="POST", status_code=200) + + data = test_metric_reader.get_metrics_data() + count = sum_counter( + find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT), + attribute_filter={attributes.OPERATION: constants.SPAN_REPLY_TO_ACTIVITY}, + ) + assert count == 1 + + +def test_connector_span_status_ok_on_success(test_exporter): + with ConnectorReplyToActivity("conv-1", "act-1"): + pass + + assert ( + test_exporter.get_finished_spans()[0].status.status_code + == trace.StatusCode.OK + ) + + +def test_connector_span_status_error_on_exception(test_exporter): + with pytest.raises(RuntimeError): + with ConnectorReplyToActivity("conv-1", "act-1"): + raise RuntimeError("connector failure") + + assert ( + test_exporter.get_finished_spans()[0].status.status_code + == trace.StatusCode.ERROR + ) + + +# ---- ConnectorSendToConversation ---- + + +def test_connector_send_to_conversation_creates_span(test_exporter): + with ConnectorSendToConversation("conv-1", "act-1"): + pass + + assert test_exporter.get_finished_spans()[0].name == constants.SPAN_SEND_TO_CONVERSATION + + +def test_connector_send_to_conversation_span_attributes(test_exporter): + with ConnectorSendToConversation("conv-2", None): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.CONVERSATION_ID] == "conv-2" + assert attributes.ACTIVITY_ID not in span.attributes + + +def test_connector_send_to_conversation_records_metrics(test_exporter, test_metric_reader): + with ConnectorSendToConversation("conv-1", None) as span: + span.share(http_method="POST", status_code=201) + + data = test_metric_reader.get_metrics_data() + assert sum_counter(find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT)) == 1 + + +# ---- ConnectorUpdateActivity ---- + + +def test_connector_update_activity_creates_span(test_exporter): + with ConnectorUpdateActivity("conv-1", "act-1"): + pass + + assert test_exporter.get_finished_spans()[0].name == constants.SPAN_UPDATE_ACTIVITY + + +def test_connector_update_activity_span_attributes(test_exporter): + with ConnectorUpdateActivity("conv-3", "act-3"): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.CONVERSATION_ID] == "conv-3" + assert span.attributes[attributes.ACTIVITY_ID] == "act-3" + + +def test_connector_update_activity_records_metrics(test_exporter, test_metric_reader): + with ConnectorUpdateActivity("conv-1", "act-1") as span: + span.share(http_method="PUT", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert sum_counter(find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT)) == 1 + + +# ---- ConnectorDeleteActivity ---- + + +def test_connector_delete_activity_creates_span(test_exporter): + with ConnectorDeleteActivity("conv-1", "act-1"): + pass + + assert test_exporter.get_finished_spans()[0].name == constants.SPAN_DELETE_ACTIVITY + + +def test_connector_delete_activity_span_attributes(test_exporter): + with ConnectorDeleteActivity("conv-4", "act-4"): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.CONVERSATION_ID] == "conv-4" + assert span.attributes[attributes.ACTIVITY_ID] == "act-4" + + +def test_connector_delete_activity_records_metrics(test_exporter, test_metric_reader): + with ConnectorDeleteActivity("conv-1", "act-1") as span: + span.share(http_method="DELETE", status_code=204) + + data = test_metric_reader.get_metrics_data() + assert sum_counter(find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT)) == 1 + + +# ---- ConnectorCreateConversation ---- + + +def test_connector_create_conversation_creates_span(test_exporter): + with ConnectorCreateConversation(): + pass + + assert ( + test_exporter.get_finished_spans()[0].name == constants.SPAN_CREATE_CONVERSATION + ) + + +def test_connector_create_conversation_has_no_conversation_or_activity_attrs( + test_exporter, +): + with ConnectorCreateConversation(): + pass + + span = test_exporter.get_finished_spans()[0] + assert attributes.CONVERSATION_ID not in span.attributes + assert attributes.ACTIVITY_ID not in span.attributes + + +def test_connector_create_conversation_records_metrics(test_exporter, test_metric_reader): + with ConnectorCreateConversation() as span: + span.share(http_method="POST", status_code=201) + + data = test_metric_reader.get_metrics_data() + assert sum_counter(find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT)) == 1 + + +# ---- ConnectorGetConversations ---- + + +def test_connector_get_conversations_creates_span(test_exporter): + with ConnectorGetConversations(): + pass + + assert test_exporter.get_finished_spans()[0].name == constants.SPAN_GET_CONVERSATIONS + + +def test_connector_get_conversations_records_metrics(test_exporter, test_metric_reader): + with ConnectorGetConversations() as span: + span.share(http_method="GET", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert sum_counter(find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT)) == 1 + + +# ---- ConnectorGetConversationMembers ---- + + +def test_connector_get_conversation_members_creates_span(test_exporter): + with ConnectorGetConversationMembers(): + pass + + assert ( + test_exporter.get_finished_spans()[0].name + == constants.SPAN_GET_CONVERSATION_MEMBERS + ) + + +def test_connector_get_conversation_members_records_metrics( + test_exporter, test_metric_reader +): + with ConnectorGetConversationMembers() as span: + span.share(http_method="GET", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert sum_counter(find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT)) == 1 + + +# ---- ConnectorUploadAttachment ---- + + +def test_connector_upload_attachment_creates_span(test_exporter): + with ConnectorUploadAttachment("conv-5"): + pass + + assert ( + test_exporter.get_finished_spans()[0].name == constants.SPAN_UPLOAD_ATTACHMENT + ) + + +def test_connector_upload_attachment_span_attributes(test_exporter): + with ConnectorUploadAttachment("conv-5"): + pass + + assert ( + test_exporter.get_finished_spans()[0].attributes[attributes.CONVERSATION_ID] + == "conv-5" + ) + + +def test_connector_upload_attachment_records_metrics(test_exporter, test_metric_reader): + with ConnectorUploadAttachment("conv-5") as span: + span.share(http_method="POST", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert sum_counter(find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT)) == 1 + + +# ---- ConnectorGetAttachmentInfo ---- + + +def test_connector_get_attachment_info_creates_span(test_exporter): + with ConnectorGetAttachmentInfo("attach-1"): + pass + + assert ( + test_exporter.get_finished_spans()[0].name == constants.SPAN_GET_ATTACHMENT_INFO + ) + + +def test_connector_get_attachment_info_span_attributes(test_exporter): + with ConnectorGetAttachmentInfo("attach-abc"): + pass + + assert ( + test_exporter.get_finished_spans()[0].attributes[attributes.ATTACHMENT_ID] + == "attach-abc" + ) + + +def test_connector_get_attachment_info_records_metrics(test_exporter, test_metric_reader): + with ConnectorGetAttachmentInfo("attach-1") as span: + span.share(http_method="GET", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert sum_counter(find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT)) == 1 + + +# ---- ConnectorGetAttachment ---- + + +def test_connector_get_attachment_creates_span(test_exporter): + with ConnectorGetAttachment("attach-1", "original"): + pass + + assert test_exporter.get_finished_spans()[0].name == constants.SPAN_GET_ATTACHMENT + + +def test_connector_get_attachment_span_attributes(test_exporter): + with ConnectorGetAttachment("attach-xyz", "thumbnail"): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.ATTACHMENT_ID] == "attach-xyz" + assert span.attributes[attributes.VIEW_ID] == "thumbnail" + + +def test_connector_get_attachment_records_metrics(test_exporter, test_metric_reader): + with ConnectorGetAttachment("attach-1", "original") as span: + span.share(http_method="GET", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert sum_counter(find_metric(data, constants.METRIC_CONNECTOR_REQUEST_COUNT)) == 1 diff --git a/tests/hosting_core/telemetry/test_http_adapter_telemetry.py b/tests/hosting_core/telemetry/test_http_adapter_telemetry.py new file mode 100644 index 00000000..74a0f47e --- /dev/null +++ b/tests/hosting_core/telemetry/test_http_adapter_telemetry.py @@ -0,0 +1,327 @@ +# Copyright (c) Microsoft Corporation. All rights reserved. +# Licensed under the MIT License. + +"""Telemetry tests for HttpAdapterBase.process_request. + +These tests verify which spans are created, what status they receive, and +which metrics fire for each code path through process_request. Several +tests deliberately assert the *current* (incorrect) behavior for known bugs +so they will fail — and thus catch regressions — once those bugs are fixed. +""" + +import pytest +from unittest.mock import AsyncMock, MagicMock +from opentelemetry import trace + +from microsoft_agents.hosting.core.http._http_adapter_base import HttpAdapterBase +from microsoft_agents.hosting.core.telemetry.adapter import constants +from microsoft_agents.hosting.core.telemetry import attributes + +from tests._common.fixtures.telemetry import ( # unused imports are needed for fixtures + test_telemetry, + test_exporter, + test_metric_reader, +) +from tests._common.telemetry_utils import find_metric, sum_counter, sum_hist_count + + +# --------------------------------------------------------------------------- +# Helpers +# --------------------------------------------------------------------------- + + +class _ConcreteAdapter(HttpAdapterBase): + """Minimal concrete subclass of HttpAdapterBase used in tests.""" + + +def _make_adapter(): + factory = MagicMock() + factory.create_connector_client = AsyncMock(return_value=MagicMock()) + factory.create_user_token_client = AsyncMock(return_value=MagicMock()) + adapter = _ConcreteAdapter(channel_service_client_factory=factory) + # Override process_activity so tests don't need real connector clients. + # Individual tests can replace this with a side_effect. + adapter.process_activity = AsyncMock(return_value=None) + return adapter + + +def _make_request(method="POST", body=None, bad_json=False): + request = AsyncMock() + request.method = method + if bad_json: + request.json = AsyncMock(side_effect=ValueError("invalid json")) + else: + request.json = AsyncMock( + return_value=body + or { + "type": "message", + "id": "act-1", + "channelId": "msteams", + "conversation": {"id": "conv-1"}, + "from": {"id": "user-1"}, + "recipient": {"id": "bot-1"}, + } + ) + request.get_claims_identity = MagicMock(return_value=None) + return request + + +def _make_agent(): + agent = MagicMock() + agent.on_turn = AsyncMock() + return agent + + +def _adapter_process_span(test_exporter): + return next( + s + for s in test_exporter.get_finished_spans() + if s.name == constants.SPAN_PROCESS + ) + + +# --------------------------------------------------------------------------- +# Happy path — valid POST with a well-formed activity +# --------------------------------------------------------------------------- + + +@pytest.mark.asyncio +async def test_valid_activity_creates_adapter_process_span(test_exporter): + adapter = _make_adapter() + await adapter.process_request(_make_request(), _make_agent()) + + span_names = [s.name for s in test_exporter.get_finished_spans()] + assert constants.SPAN_PROCESS in span_names + + +@pytest.mark.asyncio +async def test_valid_activity_span_status_is_ok(test_exporter): + adapter = _make_adapter() + await adapter.process_request(_make_request(), _make_agent()) + + span = _adapter_process_span(test_exporter) + assert span.status.status_code == trace.StatusCode.OK + + +@pytest.mark.asyncio +async def test_valid_activity_span_has_activity_attributes(test_exporter): + adapter = _make_adapter() + await adapter.process_request(_make_request(), _make_agent()) + + span = _adapter_process_span(test_exporter) + assert span.attributes[attributes.ACTIVITY_TYPE] == "message" + assert span.attributes[attributes.ACTIVITY_CHANNEL_ID] == "msteams" + + +@pytest.mark.asyncio +async def test_valid_activity_records_received_metric(test_exporter, test_metric_reader): + adapter = _make_adapter() + await adapter.process_request(_make_request(), _make_agent()) + + data = test_metric_reader.get_metrics_data() + assert sum_counter(find_metric(data, constants.METRIC_ACTIVITIES_RECEIVED)) == 1 + + +@pytest.mark.asyncio +async def test_valid_activity_received_metric_has_channel_attribute( + test_exporter, test_metric_reader +): + adapter = _make_adapter() + await adapter.process_request(_make_request(), _make_agent()) + + data = test_metric_reader.get_metrics_data() + count = sum_counter( + find_metric(data, constants.METRIC_ACTIVITIES_RECEIVED), + attribute_filter={attributes.ACTIVITY_CHANNEL_ID: "msteams"}, + ) + assert count == 1 + + +# --------------------------------------------------------------------------- +# Non-POST request +# --------------------------------------------------------------------------- + + +@pytest.mark.asyncio +async def test_non_post_request_still_creates_adapter_process_span(test_exporter): + """The span is entered before the method check, so it fires even for non-POST.""" + adapter = _make_adapter() + await adapter.process_request(_make_request(method="GET"), _make_agent()) + + span_names = [s.name for s in test_exporter.get_finished_spans()] + assert constants.SPAN_PROCESS in span_names + + +@pytest.mark.asyncio +async def test_non_post_request_span_status_is_ok(test_exporter): + """Span exits with OK because the early return is not an exception.""" + adapter = _make_adapter() + await adapter.process_request(_make_request(method="GET"), _make_agent()) + + span = _adapter_process_span(test_exporter) + assert span.status.status_code == trace.StatusCode.OK + + +@pytest.mark.asyncio +async def test_non_post_request_fires_received_metric_with_unknown_type( + test_exporter, test_metric_reader +): + """BUG: activities_received increments even for non-POST requests because + share() is never called and the metric fires with UNKNOWN type/channel_id. + Update this assertion once the bug is fixed.""" + adapter = _make_adapter() + await adapter.process_request(_make_request(method="GET"), _make_agent()) + + data = test_metric_reader.get_metrics_data() + # BUG: should be 0 — this is not a real activity + total = sum_counter(find_metric(data, constants.METRIC_ACTIVITIES_RECEIVED)) + assert total == 1 + + # The type is UNKNOWN because share() was never called + unknown_count = sum_counter( + find_metric(data, constants.METRIC_ACTIVITIES_RECEIVED), + attribute_filter={attributes.ACTIVITY_TYPE: attributes.UNKNOWN}, + ) + assert unknown_count == 1 + + +# --------------------------------------------------------------------------- +# Bad JSON body +# --------------------------------------------------------------------------- + + +@pytest.mark.asyncio +async def test_bad_json_span_status_is_ok(test_exporter): + """JSON parse error also takes the early-return path — span exits OK.""" + adapter = _make_adapter() + await adapter.process_request(_make_request(bad_json=True), _make_agent()) + + span = _adapter_process_span(test_exporter) + assert span.status.status_code == trace.StatusCode.OK + + +@pytest.mark.asyncio +async def test_bad_json_fires_received_metric_with_unknown_type( + test_exporter, test_metric_reader +): + """BUG: activities_received fires even when the body is not valid JSON.""" + adapter = _make_adapter() + await adapter.process_request(_make_request(bad_json=True), _make_agent()) + + data = test_metric_reader.get_metrics_data() + # BUG: should be 0 — no activity was ever parsed + total = sum_counter(find_metric(data, constants.METRIC_ACTIVITIES_RECEIVED)) + assert total == 1 + + +# --------------------------------------------------------------------------- +# PermissionError — span status bug +# --------------------------------------------------------------------------- + + +@pytest.mark.asyncio +async def test_permission_error_span_reports_ok_not_error(test_exporter): + """BUG: when process_activity raises PermissionError, the adapter catches it + inside the AdapterProcess with-block via `except PermissionError: return`. + Because the exception never propagates through __exit__, the span status is + set to OK instead of ERROR. This test documents the current (incorrect) + behavior — update the assertion to ERROR once the bug is fixed.""" + adapter = _make_adapter() + adapter.process_activity = AsyncMock(side_effect=PermissionError("not authorized")) + + await adapter.process_request(_make_request(), _make_agent()) + + span = _adapter_process_span(test_exporter) + # BUG: should be ERROR + assert span.status.status_code == trace.StatusCode.OK + + +@pytest.mark.asyncio +async def test_permission_error_records_received_metric(test_exporter, test_metric_reader): + """activities_received fires even when the request was unauthorized.""" + adapter = _make_adapter() + adapter.process_activity = AsyncMock(side_effect=PermissionError("not authorized")) + + await adapter.process_request(_make_request(), _make_agent()) + + data = test_metric_reader.get_metrics_data() + assert sum_counter(find_metric(data, constants.METRIC_ACTIVITIES_RECEIVED)) == 1 + + +# --------------------------------------------------------------------------- +# Unhandled exception — correct error path +# --------------------------------------------------------------------------- + + +@pytest.mark.asyncio +async def test_unhandled_exception_span_reports_error(test_exporter): + """An exception that is NOT caught inside the with-block propagates through + __exit__ and correctly marks the span ERROR.""" + adapter = _make_adapter() + adapter.process_activity = AsyncMock(side_effect=RuntimeError("unexpected")) + + with pytest.raises(RuntimeError): + await adapter.process_request(_make_request(), _make_agent()) + + span = _adapter_process_span(test_exporter) + assert span.status.status_code == trace.StatusCode.ERROR + + +@pytest.mark.asyncio +async def test_unhandled_exception_records_exception_on_span(test_exporter): + """Exception details (type, message) are recorded on the span.""" + adapter = _make_adapter() + adapter.process_activity = AsyncMock(side_effect=RuntimeError("unexpected")) + + with pytest.raises(RuntimeError): + await adapter.process_request(_make_request(), _make_agent()) + + span = _adapter_process_span(test_exporter) + assert len(span.events) > 0 + exception_event = next( + (e for e in span.events if e.name == "exception"), None + ) + assert exception_event is not None + + +# --------------------------------------------------------------------------- +# AdapterWriteResponse span (invoke path) +# --------------------------------------------------------------------------- + + +@pytest.mark.asyncio +async def test_invoke_activity_creates_write_response_span(test_exporter): + """An invoke activity takes the synchronous-response path, which wraps the + response write in a AdapterWriteResponse span.""" + adapter = _make_adapter() + invoke_response = MagicMock() + invoke_response.body = {} + invoke_response.status = 200 + adapter.process_activity = AsyncMock(return_value=invoke_response) + + await adapter.process_request( + _make_request( + body={ + "type": "invoke", + "id": "act-invoke", + "channelId": "msteams", + "conversation": {"id": "conv-1"}, + "from": {"id": "user-1"}, + "recipient": {"id": "bot-1"}, + } + ), + _make_agent(), + ) + + span_names = [s.name for s in test_exporter.get_finished_spans()] + assert constants.SPAN_WRITE_RESPONSE in span_names + + +@pytest.mark.asyncio +async def test_message_activity_does_not_create_write_response_span(test_exporter): + """Non-invoke activities return 202 Accepted without a write-response span.""" + adapter = _make_adapter() + await adapter.process_request(_make_request(), _make_agent()) + + span_names = [s.name for s in test_exporter.get_finished_spans()] + assert constants.SPAN_WRITE_RESPONSE not in span_names diff --git a/tests/hosting_core/telemetry/test_simple_span_wrapper.py b/tests/hosting_core/telemetry/test_simple_span_wrapper.py index e0e44c5b..5a57c5a5 100644 --- a/tests/hosting_core/telemetry/test_simple_span_wrapper.py +++ b/tests/hosting_core/telemetry/test_simple_span_wrapper.py @@ -116,16 +116,6 @@ def test_exception_is_recorded_on_span(self, test_exporter): assert len(exception_events) == 1 assert "type error" in exception_events[0].attributes["exception.message"] - def test_span_completion_event_on_success(self, test_exporter): - """A completion event is added on successful span execution.""" - with MinimalSpanWrapper("evt_span"): - pass - - span = test_exporter.get_finished_spans()[0] - completion_events = [e for e in span.events if "completed" in e.name] - assert len(completion_events) == 1 - assert completion_events[0].attributes["duration_ms"] >= 0 - def test_no_completion_event_on_failure(self, test_exporter): """No completion event is added when the span body raises.""" with pytest.raises(Exception): diff --git a/tests/hosting_core/telemetry/test_storage_spans.py b/tests/hosting_core/telemetry/test_storage_spans.py index 25ac7566..fbed8439 100644 --- a/tests/hosting_core/telemetry/test_storage_spans.py +++ b/tests/hosting_core/telemetry/test_storage_spans.py @@ -102,3 +102,58 @@ def test_storage_delete_records_metrics(test_exporter, test_metric_reader): data = test_metric_reader.get_metrics_data() total = sum_counter(find_metric(data, constants.METRIC_STORAGE_OPERATION_TOTAL)) assert total == 1 + + +# ---- storage.operation metric attribute value ---- + + +def test_storage_read_operation_metric_attribute_is_short_name( + test_metric_reader, +): + """storage.operation metric attribute uses the short operation name ("read"), + not the full span name ("agents.storage.read").""" + with StorageRead(key_count=1): + pass + + data = test_metric_reader.get_metrics_data() + count_with_short_name = sum_counter( + find_metric(data, constants.METRIC_STORAGE_OPERATION_TOTAL), + attribute_filter={attributes.STORAGE_OPERATION: "read"}, + ) + assert count_with_short_name == 1 + + count_with_full_name = sum_counter( + find_metric(data, constants.METRIC_STORAGE_OPERATION_TOTAL), + attribute_filter={attributes.STORAGE_OPERATION: constants.SPAN_STORAGE_READ}, + ) + assert count_with_full_name == 0 + + +def test_storage_write_operation_metric_attribute_is_short_name( + test_metric_reader, +): + """storage.operation metric attribute uses "write", not the full span name.""" + with StorageWrite(key_count=1): + pass + + data = test_metric_reader.get_metrics_data() + count_with_short_name = sum_counter( + find_metric(data, constants.METRIC_STORAGE_OPERATION_TOTAL), + attribute_filter={attributes.STORAGE_OPERATION: "write"}, + ) + assert count_with_short_name == 1 + + +def test_storage_delete_operation_metric_attribute_is_short_name( + test_metric_reader, +): + """storage.operation metric attribute uses "delete", not the full span name.""" + with StorageDelete(key_count=1): + pass + + data = test_metric_reader.get_metrics_data() + count_with_short_name = sum_counter( + find_metric(data, constants.METRIC_STORAGE_OPERATION_TOTAL), + attribute_filter={attributes.STORAGE_OPERATION: "delete"}, + ) + assert count_with_short_name == 1 diff --git a/tests/hosting_core/telemetry/test_turn_context_spans.py b/tests/hosting_core/telemetry/test_turn_context_spans.py index ca9c3db9..7ca5d355 100644 --- a/tests/hosting_core/telemetry/test_turn_context_spans.py +++ b/tests/hosting_core/telemetry/test_turn_context_spans.py @@ -3,7 +3,7 @@ from microsoft_agents.activity import Activity, ConversationAccount, ChannelAccount from microsoft_agents.hosting.core.telemetry import attributes from microsoft_agents.hosting.core.telemetry.turn_context.spans import ( - TurnContextSendActivity, + TurnContextSendActivities, ) from microsoft_agents.hosting.core.telemetry.turn_context import constants @@ -27,13 +27,13 @@ def _make_context(**activity_overrides): return SimpleNamespace(activity=activity) -# ---- TurnContextSendActivity ---- +# ---- TurnContextSendActivities ---- def test_send_activity_creates_span(test_exporter): ctx = _make_context() - with TurnContextSendActivity(ctx): + with TurnContextSendActivities(ctx): pass spans = test_exporter.get_finished_spans() @@ -44,7 +44,7 @@ def test_send_activity_creates_span(test_exporter): def test_send_activity_span_attributes(test_exporter): ctx = _make_context() - with TurnContextSendActivity(ctx): + with TurnContextSendActivities(ctx): pass span = test_exporter.get_finished_spans()[0] @@ -55,7 +55,7 @@ def test_send_activity_no_conversation(test_exporter): ctx = _make_context() ctx.activity.conversation = None - with TurnContextSendActivity(ctx): + with TurnContextSendActivities(ctx): pass span = test_exporter.get_finished_spans()[0] diff --git a/tests/hosting_core/telemetry/test_user_token_client_spans.py b/tests/hosting_core/telemetry/test_user_token_client_spans.py new file mode 100644 index 00000000..1efdb6e3 --- /dev/null +++ b/tests/hosting_core/telemetry/test_user_token_client_spans.py @@ -0,0 +1,311 @@ +# Copyright (c) Microsoft Corporation. All rights reserved. +# Licensed under the MIT License. + +import pytest +from opentelemetry import trace + +from microsoft_agents.hosting.core.telemetry import attributes +from microsoft_agents.hosting.core.connector.telemetry.user_token_client_spans import ( + GetUserToken, + SignOut, + GetSignInResource, + ExchangeToken, + GetTokenOrSignInResource, + GetTokenStatus, + GetAadTokens, +) +from microsoft_agents.hosting.core.connector.telemetry import constants + +from tests._common.fixtures.telemetry import ( # unused imports are needed for fixtures + test_telemetry, + test_exporter, + test_metric_reader, +) +from tests._common.telemetry_utils import find_metric, sum_counter, sum_hist_count + + +# ---- GetUserToken ---- + + +def test_get_user_token_creates_span(test_exporter): + with GetUserToken("conn-1", "user-1", "msteams"): + pass + + assert test_exporter.get_finished_spans()[0].name == constants.SPAN_GET_USER_TOKEN + + +def test_get_user_token_span_attributes(test_exporter): + with GetUserToken("my-connection", "user-abc", "webchat"): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.CONNECTION_NAME] == "my-connection" + assert span.attributes[attributes.USER_ID] == "user-abc" + assert span.attributes[attributes.ACTIVITY_CHANNEL_ID] == "webchat" + + +def test_get_user_token_no_channel_defaults_to_unknown(test_exporter): + with GetUserToken("conn-1", "user-1"): + pass + + assert ( + test_exporter.get_finished_spans()[0].attributes[attributes.ACTIVITY_CHANNEL_ID] + == attributes.UNKNOWN + ) + + +def test_get_user_token_records_metrics(test_exporter, test_metric_reader): + with GetUserToken("conn-1", "user-1", "msteams") as span: + span.share(http_method="GET", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert ( + sum_counter(find_metric(data, constants.METRIC_USER_TOKEN_CLIENT_REQUEST_COUNT)) + == 1 + ) + assert ( + sum_hist_count( + find_metric(data, constants.METRIC_USER_TOKEN_CLIENT_REQUEST_DURATION) + ) + == 1 + ) + + +# ---- SignOut ---- + + +def test_sign_out_creates_span(test_exporter): + with SignOut("conn-1", "user-1", "msteams"): + pass + + assert test_exporter.get_finished_spans()[0].name == constants.SPAN_SIGN_OUT + + +def test_sign_out_span_attributes(test_exporter): + with SignOut("conn-logout", "user-2", "directline"): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.CONNECTION_NAME] == "conn-logout" + assert span.attributes[attributes.USER_ID] == "user-2" + assert span.attributes[attributes.ACTIVITY_CHANNEL_ID] == "directline" + + +def test_sign_out_none_connection_name_defaults_to_unknown(test_exporter): + with SignOut(None, "user-2"): + pass + + assert ( + test_exporter.get_finished_spans()[0].attributes[attributes.CONNECTION_NAME] + == attributes.UNKNOWN + ) + + +def test_sign_out_records_metrics(test_exporter, test_metric_reader): + with SignOut("conn-1", "user-1") as span: + span.share(http_method="DELETE", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert ( + sum_counter(find_metric(data, constants.METRIC_USER_TOKEN_CLIENT_REQUEST_COUNT)) + == 1 + ) + + +# ---- GetSignInResource ---- + + +def test_get_sign_in_resource_creates_span(test_exporter): + with GetSignInResource(): + pass + + assert ( + test_exporter.get_finished_spans()[0].name == constants.SPAN_GET_SIGN_IN_RESOURCE + ) + + +def test_get_sign_in_resource_all_attributes_are_unknown(test_exporter): + """GetSignInResource accepts no parameters, so all attributes default to UNKNOWN. + NOTE: this is a known gap — connection_name should be required per the spec.""" + with GetSignInResource(): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.CONNECTION_NAME] == attributes.UNKNOWN + assert span.attributes[attributes.USER_ID] == attributes.UNKNOWN + assert span.attributes[attributes.ACTIVITY_CHANNEL_ID] == attributes.UNKNOWN + + +def test_get_sign_in_resource_records_metrics(test_exporter, test_metric_reader): + with GetSignInResource() as span: + span.share(http_method="GET", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert ( + sum_counter(find_metric(data, constants.METRIC_USER_TOKEN_CLIENT_REQUEST_COUNT)) + == 1 + ) + + +# ---- ExchangeToken ---- + + +def test_exchange_token_creates_span(test_exporter): + with ExchangeToken("conn-1", "user-1", "msteams"): + pass + + assert test_exporter.get_finished_spans()[0].name == constants.SPAN_EXCHANGE_TOKEN + + +def test_exchange_token_span_attributes(test_exporter): + with ExchangeToken("exchange-conn", "user-3", "msteams"): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.CONNECTION_NAME] == "exchange-conn" + assert span.attributes[attributes.USER_ID] == "user-3" + assert span.attributes[attributes.ACTIVITY_CHANNEL_ID] == "msteams" + + +def test_exchange_token_records_metrics(test_exporter, test_metric_reader): + with ExchangeToken("conn-1", "user-1") as span: + span.share(http_method="POST", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert ( + sum_counter(find_metric(data, constants.METRIC_USER_TOKEN_CLIENT_REQUEST_COUNT)) + == 1 + ) + + +# ---- GetTokenOrSignInResource ---- + + +def test_get_token_or_sign_in_resource_creates_span(test_exporter): + with GetTokenOrSignInResource("conn-1", "user-1"): + pass + + assert ( + test_exporter.get_finished_spans()[0].name + == constants.SPAN_GET_TOKEN_OR_SIGN_IN_RESOURCE + ) + + +def test_get_token_or_sign_in_resource_span_attributes(test_exporter): + with GetTokenOrSignInResource("tosi-conn", "user-4", "webchat"): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.CONNECTION_NAME] == "tosi-conn" + assert span.attributes[attributes.USER_ID] == "user-4" + assert span.attributes[attributes.ACTIVITY_CHANNEL_ID] == "webchat" + + +def test_get_token_or_sign_in_resource_records_metrics(test_exporter, test_metric_reader): + with GetTokenOrSignInResource("conn-1", "user-1") as span: + span.share(http_method="GET", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert ( + sum_counter(find_metric(data, constants.METRIC_USER_TOKEN_CLIENT_REQUEST_COUNT)) + == 1 + ) + + +# ---- GetTokenStatus ---- + + +def test_get_token_status_creates_span(test_exporter): + with GetTokenStatus("user-1", "msteams"): + pass + + assert test_exporter.get_finished_spans()[0].name == constants.SPAN_GET_TOKEN_STATUS + + +def test_get_token_status_span_attributes(test_exporter): + with GetTokenStatus("user-5", "directline"): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.USER_ID] == "user-5" + assert span.attributes[attributes.ACTIVITY_CHANNEL_ID] == "directline" + # GetTokenStatus takes no connection_name — defaults to UNKNOWN + assert span.attributes[attributes.CONNECTION_NAME] == attributes.UNKNOWN + + +def test_get_token_status_records_metrics(test_exporter, test_metric_reader): + with GetTokenStatus("user-1") as span: + span.share(http_method="GET", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert ( + sum_counter(find_metric(data, constants.METRIC_USER_TOKEN_CLIENT_REQUEST_COUNT)) + == 1 + ) + + +# ---- GetAadTokens ---- + + +def test_get_aad_tokens_creates_span(test_exporter): + with GetAadTokens("conn-1", "user-1", "msteams"): + pass + + assert test_exporter.get_finished_spans()[0].name == constants.SPAN_GET_AAD_TOKENS + + +def test_get_aad_tokens_span_attributes(test_exporter): + with GetAadTokens("aad-conn", "user-6", "msteams"): + pass + + span = test_exporter.get_finished_spans()[0] + assert span.attributes[attributes.CONNECTION_NAME] == "aad-conn" + assert span.attributes[attributes.USER_ID] == "user-6" + assert span.attributes[attributes.ACTIVITY_CHANNEL_ID] == "msteams" + + +def test_get_aad_tokens_records_metrics(test_exporter, test_metric_reader): + with GetAadTokens("conn-1", "user-1") as span: + span.share(http_method="GET", status_code=200) + + data = test_metric_reader.get_metrics_data() + assert ( + sum_counter(find_metric(data, constants.METRIC_USER_TOKEN_CLIENT_REQUEST_COUNT)) + == 1 + ) + + +# ---- share() / _RequestSpanWrapper behavior ---- + + +def test_share_http_attrs_go_to_metrics_not_span(test_exporter, test_metric_reader): + """HTTP method and status code appear in metrics but not on the span itself.""" + with GetUserToken("conn-1", "user-1") as span: + span.share(http_method="GET", status_code=200) + + finished = test_exporter.get_finished_spans()[0] + # Not on the span + assert attributes.HTTP_METHOD not in finished.attributes + assert attributes.HTTP_STATUS_CODE not in finished.attributes + + # Present in metrics + data = test_metric_reader.get_metrics_data() + count = sum_counter( + find_metric(data, constants.METRIC_USER_TOKEN_CLIENT_REQUEST_COUNT), + attribute_filter={ + attributes.HTTP_METHOD: "GET", + attributes.HTTP_STATUS_CODE: 200, + }, + ) + assert count == 1 + + +def test_user_token_span_status_error_on_exception(test_exporter): + with pytest.raises(ValueError): + with GetUserToken("conn-1", "user-1"): + raise ValueError("token error") + + assert ( + test_exporter.get_finished_spans()[0].status.status_code + == trace.StatusCode.ERROR + ) From 00607496a00eae28069ea0bf2b3e6afe5b7fbe26 Mon Sep 17 00:00:00 2001 From: Rodrigo Brandao Date: Tue, 14 Apr 2026 17:23:19 -0700 Subject: [PATCH 2/5] Formatting --- .../microsoft_agents/hosting/core/telemetry/attributes.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/attributes.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/attributes.py index 4b1adc9b..ae35fe27 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/attributes.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/attributes.py @@ -26,7 +26,7 @@ HTTP_METHOD = "http.method" HTTP_STATUS_CODE = "http.status_code" -IS_AGENTIC = "is_agentic_request" +IS_AGENTIC = "activity.is_agentic_request" KEY_COUNT = "storage.keys.count" From ff682bf46e722f9a7a5b9f5817be004873e64dab Mon Sep 17 00:00:00 2001 From: Rodrigo Brandao Date: Tue, 14 Apr 2026 17:25:00 -0700 Subject: [PATCH 3/5] TurnContext span rename --- .../hosting/core/storage/telemetry/spans.py | 1 + .../hosting/core/telemetry/adapter/spans.py | 3 ++- .../core/telemetry/turn_context/constants.py | 2 +- .../core/telemetry/turn_context/spans.py | 4 +-- .../hosting/core/turn_context.py | 1 + .../hosting_core/telemetry/test_app_spans.py | 4 +-- .../telemetry/test_connector_spans.py | 25 +++++++++++++------ .../telemetry/test_http_adapter_telemetry.py | 13 +++++----- .../telemetry/test_turn_context_spans.py | 2 +- .../telemetry/test_user_token_client_spans.py | 8 +++--- 10 files changed, 38 insertions(+), 25 deletions(-) diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/storage/telemetry/spans.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/storage/telemetry/spans.py index 764c9f7d..f4808933 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/storage/telemetry/spans.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/storage/telemetry/spans.py @@ -62,6 +62,7 @@ def __init__(self, key_count: int): """Initializes the StorageWrite span.""" super().__init__(constants.SPAN_STORAGE_WRITE, "write", key_count=key_count) + class StorageDelete(_StorageSpanWrapper): """Span for deleting from storage.""" diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/spans.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/spans.py index 4cba9ee8..fa70bff0 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/spans.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/adapter/spans.py @@ -197,6 +197,7 @@ def _get_attributes(self) -> AttributeMap: attributes.IS_AGENTIC: self._is_agentic_request, } + class AdapterWriteResponse(SimpleSpanWrapper): """Span for writing an InvokeResponse in the adapter. This captures the handling of expectReplies, invoke, and streaming""" @@ -219,4 +220,4 @@ def _get_attributes(self) -> AttributeMap: """Returns a dictionary of attributes to set on the span when it is started. This includes attributes related to the activities being sent.""" return { attributes.CONVERSATION_ID: get_conversation_id(self._activity), - } \ No newline at end of file + } diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/constants.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/constants.py index b8155e78..22800a12 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/constants.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/constants.py @@ -1,4 +1,4 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License. -SPAN_TURN_SEND_ACTIVITY = "agents.turn.send_activity" +SPAN_TURN_SEND_ACTIVITIES = "agents.turn.send_activities" diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/spans.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/spans.py index 9fba48a2..476d9e9d 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/spans.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/telemetry/turn_context/spans.py @@ -14,10 +14,10 @@ class TurnContextSendActivities(SimpleSpanWrapper): - """Span wrapper for sending an activity within a turn context.""" + """Span wrapper for sending activities within a turn context.""" def __init__(self, turn_context: TurnContextProtocol): - super().__init__(constants.SPAN_TURN_SEND_ACTIVITY) + super().__init__(constants.SPAN_TURN_SEND_ACTIVITIES) self._turn_context = turn_context def _get_attributes(self) -> AttributeMap: diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/turn_context.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/turn_context.py index 9452aed9..46eeba4a 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/turn_context.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/turn_context.py @@ -22,6 +22,7 @@ from microsoft_agents.hosting.core.authorization.claims_identity import ClaimsIdentity import microsoft_agents.hosting.core.telemetry.turn_context.spans as spans + class TurnContext(TurnContextProtocol): # Same constant as in the BF Adapter, duplicating here to avoid circular dependency _INVOKE_RESPONSE_KEY = "TurnContext.InvokeResponse" diff --git a/tests/hosting_core/telemetry/test_app_spans.py b/tests/hosting_core/telemetry/test_app_spans.py index 14699fed..45ac5eb2 100644 --- a/tests/hosting_core/telemetry/test_app_spans.py +++ b/tests/hosting_core/telemetry/test_app_spans.py @@ -101,9 +101,7 @@ def test_app_on_turn_records_error_metric_on_exception( assert success_count == 0 -def test_app_on_turn_records_turn_duration_on_error( - test_exporter, test_metric_reader -): +def test_app_on_turn_records_turn_duration_on_error(test_exporter, test_metric_reader): """turn_duration is recorded on both success and error paths.""" ctx = _make_context() diff --git a/tests/hosting_core/telemetry/test_connector_spans.py b/tests/hosting_core/telemetry/test_connector_spans.py index 4121498d..1ee68eca 100644 --- a/tests/hosting_core/telemetry/test_connector_spans.py +++ b/tests/hosting_core/telemetry/test_connector_spans.py @@ -26,7 +26,6 @@ ) from tests._common.telemetry_utils import find_metric, sum_counter, sum_hist_count - # ---- ConnectorReplyToActivity ---- @@ -117,8 +116,7 @@ def test_connector_span_status_ok_on_success(test_exporter): pass assert ( - test_exporter.get_finished_spans()[0].status.status_code - == trace.StatusCode.OK + test_exporter.get_finished_spans()[0].status.status_code == trace.StatusCode.OK ) @@ -140,7 +138,10 @@ def test_connector_send_to_conversation_creates_span(test_exporter): with ConnectorSendToConversation("conv-1", "act-1"): pass - assert test_exporter.get_finished_spans()[0].name == constants.SPAN_SEND_TO_CONVERSATION + assert ( + test_exporter.get_finished_spans()[0].name + == constants.SPAN_SEND_TO_CONVERSATION + ) def test_connector_send_to_conversation_span_attributes(test_exporter): @@ -152,7 +153,9 @@ def test_connector_send_to_conversation_span_attributes(test_exporter): assert attributes.ACTIVITY_ID not in span.attributes -def test_connector_send_to_conversation_records_metrics(test_exporter, test_metric_reader): +def test_connector_send_to_conversation_records_metrics( + test_exporter, test_metric_reader +): with ConnectorSendToConversation("conv-1", None) as span: span.share(http_method="POST", status_code=201) @@ -237,7 +240,9 @@ def test_connector_create_conversation_has_no_conversation_or_activity_attrs( assert attributes.ACTIVITY_ID not in span.attributes -def test_connector_create_conversation_records_metrics(test_exporter, test_metric_reader): +def test_connector_create_conversation_records_metrics( + test_exporter, test_metric_reader +): with ConnectorCreateConversation() as span: span.share(http_method="POST", status_code=201) @@ -252,7 +257,9 @@ def test_connector_get_conversations_creates_span(test_exporter): with ConnectorGetConversations(): pass - assert test_exporter.get_finished_spans()[0].name == constants.SPAN_GET_CONVERSATIONS + assert ( + test_exporter.get_finished_spans()[0].name == constants.SPAN_GET_CONVERSATIONS + ) def test_connector_get_conversations_records_metrics(test_exporter, test_metric_reader): @@ -338,7 +345,9 @@ def test_connector_get_attachment_info_span_attributes(test_exporter): ) -def test_connector_get_attachment_info_records_metrics(test_exporter, test_metric_reader): +def test_connector_get_attachment_info_records_metrics( + test_exporter, test_metric_reader +): with ConnectorGetAttachmentInfo("attach-1") as span: span.share(http_method="GET", status_code=200) diff --git a/tests/hosting_core/telemetry/test_http_adapter_telemetry.py b/tests/hosting_core/telemetry/test_http_adapter_telemetry.py index 74a0f47e..9edfa872 100644 --- a/tests/hosting_core/telemetry/test_http_adapter_telemetry.py +++ b/tests/hosting_core/telemetry/test_http_adapter_telemetry.py @@ -24,7 +24,6 @@ ) from tests._common.telemetry_utils import find_metric, sum_counter, sum_hist_count - # --------------------------------------------------------------------------- # Helpers # --------------------------------------------------------------------------- @@ -114,7 +113,9 @@ async def test_valid_activity_span_has_activity_attributes(test_exporter): @pytest.mark.asyncio -async def test_valid_activity_records_received_metric(test_exporter, test_metric_reader): +async def test_valid_activity_records_received_metric( + test_exporter, test_metric_reader +): adapter = _make_adapter() await adapter.process_request(_make_request(), _make_agent()) @@ -237,7 +238,9 @@ async def test_permission_error_span_reports_ok_not_error(test_exporter): @pytest.mark.asyncio -async def test_permission_error_records_received_metric(test_exporter, test_metric_reader): +async def test_permission_error_records_received_metric( + test_exporter, test_metric_reader +): """activities_received fires even when the request was unauthorized.""" adapter = _make_adapter() adapter.process_activity = AsyncMock(side_effect=PermissionError("not authorized")) @@ -278,9 +281,7 @@ async def test_unhandled_exception_records_exception_on_span(test_exporter): span = _adapter_process_span(test_exporter) assert len(span.events) > 0 - exception_event = next( - (e for e in span.events if e.name == "exception"), None - ) + exception_event = next((e for e in span.events if e.name == "exception"), None) assert exception_event is not None diff --git a/tests/hosting_core/telemetry/test_turn_context_spans.py b/tests/hosting_core/telemetry/test_turn_context_spans.py index 7ca5d355..dfb8ec4a 100644 --- a/tests/hosting_core/telemetry/test_turn_context_spans.py +++ b/tests/hosting_core/telemetry/test_turn_context_spans.py @@ -38,7 +38,7 @@ def test_send_activity_creates_span(test_exporter): spans = test_exporter.get_finished_spans() assert len(spans) == 1 - assert spans[0].name == constants.SPAN_TURN_SEND_ACTIVITY + assert spans[0].name == constants.SPAN_TURN_SEND_ACTIVITIES def test_send_activity_span_attributes(test_exporter): diff --git a/tests/hosting_core/telemetry/test_user_token_client_spans.py b/tests/hosting_core/telemetry/test_user_token_client_spans.py index 1efdb6e3..d6ab8fdb 100644 --- a/tests/hosting_core/telemetry/test_user_token_client_spans.py +++ b/tests/hosting_core/telemetry/test_user_token_client_spans.py @@ -23,7 +23,6 @@ ) from tests._common.telemetry_utils import find_metric, sum_counter, sum_hist_count - # ---- GetUserToken ---- @@ -120,7 +119,8 @@ def test_get_sign_in_resource_creates_span(test_exporter): pass assert ( - test_exporter.get_finished_spans()[0].name == constants.SPAN_GET_SIGN_IN_RESOURCE + test_exporter.get_finished_spans()[0].name + == constants.SPAN_GET_SIGN_IN_RESOURCE ) @@ -201,7 +201,9 @@ def test_get_token_or_sign_in_resource_span_attributes(test_exporter): assert span.attributes[attributes.ACTIVITY_CHANNEL_ID] == "webchat" -def test_get_token_or_sign_in_resource_records_metrics(test_exporter, test_metric_reader): +def test_get_token_or_sign_in_resource_records_metrics( + test_exporter, test_metric_reader +): with GetTokenOrSignInResource("conn-1", "user-1") as span: span.share(http_method="GET", status_code=200) From 5fa91cc8a3a93507b87f3ff62430a224ecc9ebcc Mon Sep 17 00:00:00 2001 From: Rodrigo Brandao Date: Tue, 14 Apr 2026 17:27:30 -0700 Subject: [PATCH 4/5] Metric name change --- .../hosting/core/authorization/telemetry/constants.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/authorization/telemetry/constants.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/authorization/telemetry/constants.py index d782e389..c4ee8860 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/authorization/telemetry/constants.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/authorization/telemetry/constants.py @@ -10,8 +10,8 @@ # Metrics -METRIC_AUTH_TOKEN_REQUEST_DURATION = "agents.auth.token.duration" -METRIC_AUTH_TOKEN_REQUEST_COUNT = "agents.auth.token.count" +METRIC_AUTH_TOKEN_REQUEST_DURATION = "agents.auth.token.request.duration" +METRIC_AUTH_TOKEN_REQUEST_COUNT = "agents.auth.token.request.count" AUTH_METHOD_OBO = "obo" AUTH_METHOD_AGENTIC_INSTANCE = "agentic_instance" From 226b6465c498b27c7c2b97853687c72ae9b35b38 Mon Sep 17 00:00:00 2001 From: Rodrigo Brandao Date: Wed, 15 Apr 2026 11:56:15 -0700 Subject: [PATCH 5/5] Addressing PR comments --- .../core/connector/client/connector_client.py | 4 ++-- .../telemetry/test_http_adapter_telemetry.py | 21 +++++++------------ 2 files changed, 9 insertions(+), 16 deletions(-) diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/client/connector_client.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/client/connector_client.py index 5785b94e..777c685a 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/client/connector_client.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/connector/client/connector_client.py @@ -349,8 +349,8 @@ async def update_activity( ) response.raise_for_status() - data = await response.json() - return ResourceResponse.model_validate(data) + data = await response.json() + return ResourceResponse.model_validate(data) async def delete_activity(self, conversation_id: str, activity_id: str) -> None: """ diff --git a/tests/hosting_core/telemetry/test_http_adapter_telemetry.py b/tests/hosting_core/telemetry/test_http_adapter_telemetry.py index 9edfa872..b7ed889a 100644 --- a/tests/hosting_core/telemetry/test_http_adapter_telemetry.py +++ b/tests/hosting_core/telemetry/test_http_adapter_telemetry.py @@ -4,9 +4,7 @@ """Telemetry tests for HttpAdapterBase.process_request. These tests verify which spans are created, what status they receive, and -which metrics fire for each code path through process_request. Several -tests deliberately assert the *current* (incorrect) behavior for known bugs -so they will fail — and thus catch regressions — once those bugs are fixed. +which metrics fire for each code path through process_request. """ import pytest @@ -167,14 +165,12 @@ async def test_non_post_request_span_status_is_ok(test_exporter): async def test_non_post_request_fires_received_metric_with_unknown_type( test_exporter, test_metric_reader ): - """BUG: activities_received increments even for non-POST requests because - share() is never called and the metric fires with UNKNOWN type/channel_id. - Update this assertion once the bug is fixed.""" + """activities_received increments for non-POST requests with UNKNOWN type/channel_id + because share() is never called.""" adapter = _make_adapter() await adapter.process_request(_make_request(method="GET"), _make_agent()) data = test_metric_reader.get_metrics_data() - # BUG: should be 0 — this is not a real activity total = sum_counter(find_metric(data, constants.METRIC_ACTIVITIES_RECEIVED)) assert total == 1 @@ -205,12 +201,11 @@ async def test_bad_json_span_status_is_ok(test_exporter): async def test_bad_json_fires_received_metric_with_unknown_type( test_exporter, test_metric_reader ): - """BUG: activities_received fires even when the body is not valid JSON.""" + """activities_received fires even when the body is not valid JSON.""" adapter = _make_adapter() await adapter.process_request(_make_request(bad_json=True), _make_agent()) data = test_metric_reader.get_metrics_data() - # BUG: should be 0 — no activity was ever parsed total = sum_counter(find_metric(data, constants.METRIC_ACTIVITIES_RECEIVED)) assert total == 1 @@ -221,19 +216,17 @@ async def test_bad_json_fires_received_metric_with_unknown_type( @pytest.mark.asyncio -async def test_permission_error_span_reports_ok_not_error(test_exporter): - """BUG: when process_activity raises PermissionError, the adapter catches it +async def test_permission_error_span_status_is_ok(test_exporter): + """When process_activity raises PermissionError, the adapter catches it inside the AdapterProcess with-block via `except PermissionError: return`. Because the exception never propagates through __exit__, the span status is - set to OK instead of ERROR. This test documents the current (incorrect) - behavior — update the assertion to ERROR once the bug is fixed.""" + set to OK instead of ERROR.""" adapter = _make_adapter() adapter.process_activity = AsyncMock(side_effect=PermissionError("not authorized")) await adapter.process_request(_make_request(), _make_agent()) span = _adapter_process_span(test_exporter) - # BUG: should be ERROR assert span.status.status_code == trace.StatusCode.OK