From c261f922462f8972bd0a98fddc6d8babaa769eee Mon Sep 17 00:00:00 2001 From: Dave Taniguchi Date: Sat, 10 Aug 2019 14:06:51 -0700 Subject: [PATCH 1/5] Add Telemetry Logger --- .../botbuilder/core/__init__.py | 6 + .../botbuilder/core/middleware_set.py | 2 +- .../botbuilder/core/telemetry_constants.py | 18 ++ .../core/telemetry_logger_constants.py | 16 ++ .../core/telemetry_logger_middleware.py | 252 ++++++++++++++++++ .../tests/test_telemetry_middleware.py | 162 +++++++++++ 6 files changed, 455 insertions(+), 1 deletion(-) create mode 100644 libraries/botbuilder-core/botbuilder/core/telemetry_constants.py create mode 100644 libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py create mode 100644 libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py create mode 100644 libraries/botbuilder-core/tests/test_telemetry_middleware.py diff --git a/libraries/botbuilder-core/botbuilder/core/__init__.py b/libraries/botbuilder-core/botbuilder/core/__init__.py index f5e6c0ef8..d57367813 100644 --- a/libraries/botbuilder-core/botbuilder/core/__init__.py +++ b/libraries/botbuilder-core/botbuilder/core/__init__.py @@ -29,6 +29,9 @@ from .state_property_accessor import StatePropertyAccessor from .state_property_info import StatePropertyInfo from .storage import Storage, StoreItem, calculate_change_hash +from .telemetry_constants import TelemetryConstants +from .telemetry_logger_constants import TelemetryLoggerConstants +from .telemetry_logger_middleware import TelemetryLoggerMiddleware from .turn_context import TurnContext from .user_state import UserState from .user_token_provider import UserTokenProvider @@ -63,6 +66,9 @@ "StatePropertyInfo", "Storage", "StoreItem", + "TelemetryConstants", + "TelemetryLoggerConstants", + "TelemetryLoggerMiddleware", "TopIntent", "TurnContext", "UserState", diff --git a/libraries/botbuilder-core/botbuilder/core/middleware_set.py b/libraries/botbuilder-core/botbuilder/core/middleware_set.py index eae91b94b..88dbf812a 100644 --- a/libraries/botbuilder-core/botbuilder/core/middleware_set.py +++ b/libraries/botbuilder-core/botbuilder/core/middleware_set.py @@ -10,7 +10,7 @@ class Middleware(ABC): @abstractmethod - def on_process_request( + async def on_process_request( self, context: TurnContext, logic: Callable[[TurnContext], Awaitable] ): pass diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py b/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py new file mode 100644 index 000000000..42e1390f2 --- /dev/null +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py @@ -0,0 +1,18 @@ +# Copyright (c) Microsoft Corporation. All rights reserved. +# Licensed under the MIT License + +class TelemetryConstants(object): + """Telemetry logger property names.""" + CHANNEL_ID_PROPERTY: str = 'channelId' + CONVERSATION_ID_PROPERTY: str = 'conversationId' + CONVERSATION_NAME_PROPERTY: str = 'conversationName' + DIALOG_ID_PROPERTY: str = 'dialogId' + FROM_ID_PROPERTY: str = 'fromId' + FROM_NAME_PROPERTY: str = 'fromName' + LOCALE_PROPERTY: str = 'locale' + RECIPIENT_ID_PROPERTY: str = 'recipientId' + RECIPIENT_NAME_PROPERTY: str = 'recipientName' + REPLY_ACTIVITY_ID_PROPERTY: str = 'replyActivityId' + TEXT_PROPERTY: str = 'text' + SPEAK_PROPERTY: str = 'speak' + USER_ID_PROPERTY: str = 'userId' diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py new file mode 100644 index 000000000..f248abd2c --- /dev/null +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py @@ -0,0 +1,16 @@ +# Copyright (c) Microsoft Corporation. All rights reserved. +# Licensed under the MIT License + +class TelemetryLoggerConstants(object): + """The Telemetry Logger Event names.""" + # The name of the event when a new message is received from the user. + BOT_MSG_RECEIVE_EVENT: str = "BotMessageReceived" + + # The name of the event when logged when a message is sent from the bot to the user. + BOT_MSG_SEND_EVENT: str = "BotMessageSend" + + # The name of the event when a message is updated by the bot. + BOT_MSG_UPDATE_EVENT: str = "BotMessageUpdate" + + # The name of the event when a message is deleted by the bot. + BOT_MSG_DELETE_EVENT: str = "BotMessageDelete" diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py new file mode 100644 index 000000000..cc5ff5bf7 --- /dev/null +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py @@ -0,0 +1,252 @@ +# Copyright (c) Microsoft Corporation. All rights reserved. +# Licensed under the MIT License. +"""Middleware Component for logging Activity messages.""" + +from typing import Awaitable, Callable, List, Dict +from .bot_telemetry_client import BotTelemetryClient +from .bot_state import BotState +from .bot_assert import BotAssert +from .bot_state_set import BotStateSet +from .middleware_set import Middleware +from .null_telemetry_client import NullTelemetryClient +from .turn_context import TurnContext +from .telemetry_constants import TelemetryConstants +from .telemetry_logger_constants import TelemetryLoggerConstants +from botbuilder.schema import Activity, ConversationReference, ActivityTypes + +# pylint: disable=line-too-long +class TelemetryLoggerMiddleware(Middleware): + """Middleware for logging incoming, outgoing, updated or deleted Activity messages.""" + def __init__(self, telemetry_client: BotTelemetryClient, log_personal_information: bool) -> None: + super(TelemetryLoggerMiddleware, self).__init__() + self._telemetry_client = telemetry_client or NullTelemetryClient() + self._log_personal_information = log_personal_information + + @property + def telemetry_client(self) -> BotTelemetryClient: + """Gets the currently configured BotTelemetryClient.""" + return self._telemetry_client + + @property + def log_personal_information(self) -> bool: + """ Gets a value indicating whether determines whether to log personal + information that came from the user.""" + return self._log_personal_information + + async def on_process_request(self, context: TurnContext, + logic_fn: Callable[[TurnContext], Awaitable]) -> None: + """Logs events based on incoming and outgoing activities using + BotTelemetryClient base class + + :param turn_context: The context object for this turn. + :param logic: Callable to continue the bot middleware pipeline + + :return: None + """ + BotAssert.context_not_none(context) + + # Log incoming activity at beginning of turn + if context.activity: + activity = context.activity + # Log Bot Message Received + await self.on_receive_activity(activity) + + # hook up onSend pipeline + # pylint: disable=unused-argument + async def send_activities_handler(ctx: TurnContext, activities: List[Activity], + next_send: Callable[[], Awaitable[None]]): + # Run full pipeline + responses = await next_send() + for activity in activities: + await self.on_send_activity(activity) + return responses + + context.on_send_activities(send_activities_handler) + + # hook up update activity pipeline + async def update_activity_handler(ctx: TurnContext, activity: Activity, + next_update: Callable[[], Awaitable]): + # Run full pipeline + response = await next_update() + await self.on_update_activity(activity) + return response + + context.on_update_activity(update_activity_handler) + + # hook up delete activity pipeline + async def delete_activity_handler(ctx: TurnContext, reference: ConversationReference, + next_delete: Callable[[], Awaitable]): + # Run full pipeline + await next_delete() + + delete_msg = Activity(type=ActivityTypes.message_delete, + id=reference.activity_id) + deleted_activity: Activity = TurnContext.apply_conversation_reference(delete_msg, reference, False) + await self.on_delete_activity(deleted_activity) + + context.on_delete_activity(delete_activity_handler) + + if logic_fn: + await logic_fn() + + + async def on_receive_activity(self, activity: Activity) -> None: + """Invoked when a message is received from the user. + Performs logging of telemetry data using the BotTelemetryClient.track_event() method. + This event name used is "BotMessageReceived". + :param activity: Current activity sent from user. + """ + self.telemetry_client.track_event(TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, + await self.fill_receive_event_properties(activity)) + + async def on_send_activity(self, activity: Activity) -> None: + """Invoked when the bot sends a message to the user. + Performs logging of telemetry data using the BotTelemetryClient.track_event() method. + This event name used is "BotMessageSend". + :param activity: Current activity sent from bot. + """ + self.telemetry_client.track_event(TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, + await self.fill_send_event_properties(activity)) + + async def on_update_activity(self, activity: Activity) -> None: + """Invoked when the bot updates a message. + Performs logging of telemetry data using the BotTelemetryClient.track_event() method. + This event name used is "BotMessageUpdate". + :param activity: Current activity sent from user. + """ + self.telemetry_client.track_event(TelemetryLoggerConstants.BOT_MSG_UPDATE_EVENT, + await self.fill_update_event_properties(activity)) + + async def on_delete_activity(self, activity: Activity) -> None: + """Invoked when the bot deletes a message. + Performs logging of telemetry data using the BotTelemetryClient.track_event() method. + This event name used is "BotMessageDelete". + :param activity: Current activity sent from user. + """ + self.telemetry_client.track_event(TelemetryLoggerConstants.BOT_MSG_DELETE_EVENT, + await self.fill_delete_event_properties(activity)) + + + async def fill_receive_event_properties(self, activity: Activity, + additional_properties: Dict[str, str] = None) -> Dict[str, str]: + """Fills the event properties for the BotMessageReceived. + Adheres to the LogPersonalInformation flag to filter Name, Text and Speak properties. + :param activity: activity sent from user. + :param additional_properties: Additional properties to add to the event. + Additional properties can override "stock" properties. + + :return: A dictionary that is sent as "Properties" to + BotTelemetryClient.track_event method for the BotMessageReceived event. + """ + properties = { + TelemetryConstants.FROM_ID_PROPERTY : activity.from_property.id, + TelemetryConstants.CONVERSATION_NAME_PROPERTY : activity.conversation.name, + TelemetryConstants.LOCALE_PROPERTY : activity.locale, + TelemetryConstants.RECIPIENT_ID_PROPERTY : activity.recipient.id, + TelemetryConstants.RECIPIENT_NAME_PROPERTY : activity.from_property.name, + } + + if self.log_personal_information: + if activity.from_property.name and activity.from_property.name.strip(): + properties[TelemetryConstants.FROM_NAME_PROPERTY] = activity.from_property.name + if activity.text and activity.text.strip(): + properties[TelemetryConstants.TEXT_PROPERTY] = activity.text + if activity.speak and activity.speak.strip(): + properties[TelemetryConstants.SPEAK_PROPERTY] = activity.speak + + # Additional properties can override "stock" properties + if additional_properties: + for prop in additional_properties: + properties[prop.key] = prop.value + + return properties + + async def fill_send_event_properties(self, activity: Activity, + additional_properties: Dict[str, str] = None) -> Dict[str, str]: + """Fills the event properties for the BotMessageSend. + These properties are logged when an activity message is sent by the Bot to the user. + :param activity: activity sent from user. + :param additional_properties: Additional properties to add to the event. + Additional properties can override "stock" properties. + + :return: A dictionary that is sent as "Properties" to the + BotTelemetryClient.track_event method for the BotMessageSend event. + """ + properties = { + TelemetryConstants.REPLY_ACTIVITY_ID_PROPERTY : activity.reply_to_id, + TelemetryConstants.RECIPIENT_ID_PROPERTY : activity.recipient.id, + TelemetryConstants.CONVERSATION_NAME_PROPERTY : activity.conversation.name, + TelemetryConstants.LOCALE_PROPERTY : activity.locale, + } + + # Use the LogPersonalInformation flag to toggle logging PII data, text and user name are common examples + if self.log_personal_information: + if activity.from_property.name and activity.from_property.name.strip(): + properties[TelemetryConstants.FROM_NAME_PROPERTY] = activity.from_property.name + if activity.text and activity.text.strip(): + properties[TelemetryConstants.TEXT_PROPERTY] = activity.text + if activity.speak and activity.speak.strip(): + properties[TelemetryConstants.SPEAK_PROPERTY] = activity.speak + + # Additional properties can override "stock" properties + if additional_properties: + for prop in additional_properties: + properties[prop.key] = prop.value + + return properties + + async def fill_update_event_properties(self, activity: Activity, + additional_properties: Dict[str, str] = None) -> Dict[str, str]: + """Fills the event properties for the BotMessageUpdate. + These properties are logged when an activity message is updated by the Bot. + For example, if a card is interacted with by the use, and the card needs + to be updated to reflect some interaction. + :param activity: activity sent from user. + :param additional_properties: Additional properties to add to the event. + Additional properties can override "stock" properties. + + :return: A dictionary that is sent as "Properties" to the + BotTelemetryClient.track_event method for the BotMessageUpdate event. + """ + properties = { + TelemetryConstants.RECIPIENT_ID_PROPERTY : activity.recipient.id, + TelemetryConstants.CONVERSATION_ID_PROPERTY : activity.conversation.id, + TelemetryConstants.CONVERSATION_NAME_PROPERTY : activity.conversation.name, + TelemetryConstants.LOCALE_PROPERTY : activity.locale, + } + + # Use the LogPersonalInformation flag to toggle logging PII data, text is a common examples + if self.log_personal_information: + if activity.text and activity.text.strip(): + properties[TelemetryConstants.TEXT_PROPERTY] = activity.text + + # Additional properties can override "stock" properties + if additional_properties: + for prop in additional_properties: + properties[prop.key] = prop.value + + return properties + + async def fill_delete_event_properties(self, activity: Activity, + additional_properties: Dict[str, str] = None) -> Dict[str, str]: + """Fills the event properties for the BotMessageDelete. + These properties are logged when an activity message is deleted by the Bot. + :param activity: activity sent from user. + :param additional_properties: Additional properties to add to the event. + Additional properties can override "stock" properties. + + :return: A dictionary that is sent as "Properties" to the + BotTelemetryClient.track_event method for the BotMessageUpdate event. + """ + properties = { + TelemetryConstants.RECIPIENT_ID_PROPERTY : activity.recipient.id, + TelemetryConstants.CONVERSATION_ID_PROPERTY : activity.conversation.id, + TelemetryConstants.CONVERSATION_NAME_PROPERTY : activity.conversation.name, + } + + # Additional properties can override "stock" properties + if additional_properties: + for prop in additional_properties: + properties[prop.key] = prop.value + + return properties diff --git a/libraries/botbuilder-core/tests/test_telemetry_middleware.py b/libraries/botbuilder-core/tests/test_telemetry_middleware.py new file mode 100644 index 000000000..89cd7f4e5 --- /dev/null +++ b/libraries/botbuilder-core/tests/test_telemetry_middleware.py @@ -0,0 +1,162 @@ +# Copyright (c) Microsoft Corporation. All rights reserved. +# Licensed under the MIT License. + +import sys +import copy +from typing import Awaitable, Callable, Dict +import aiounittest + +from unittest.mock import patch, Mock +from botbuilder.core import ( + AnonymousReceiveMiddleware, + BotTelemetryClient, + MiddlewareSet, + Middleware, + NullTelemetryClient, + TelemetryLoggerMiddleware, + TelemetryLoggerConstants, + TurnContext, +) +from botbuilder.core.adapters import TestAdapter, TestFlow +from botbuilder.schema import ( + Activity, + ActivityTypes, + ChannelAccount, + ConversationAccount, + ConversationReference, +) + +#pylint: disable=line-too-long,missing-docstring +class TestTelemetryMiddleware(aiounittest.AsyncTestCase): + # pylint: disable=unused-argument + async def test_create_middleware(self): + telemetry = NullTelemetryClient() + my_logger = TelemetryLoggerMiddleware(telemetry, True) + assert(my_logger) + + async def test_should_send_receive(self): + telemetry = Mock() + my_logger = TelemetryLoggerMiddleware(telemetry, True) + + async def logic(context: TurnContext): + await context.send_activity(f'echo:{context.activity.text}') + + adapter = TestAdapter(logic) + adapter.use(my_logger) + test_flow = TestFlow(None, adapter) + test_flow = await test_flow.send('foo') + test_flow = await test_flow.assert_reply('echo:foo') + test_flow = await test_flow.send('bar') + await test_flow.assert_reply('echo:bar') + + # assert + # Note: None values just check for existence of the key, not the explicit + # value (generated) + telemetry_calls = [ + (TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, {"text":"foo", "fromId": "User1", "conversationName": None, "locale":None, + "recipientId" : "bot", "recipientName": 'user', }), + (TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, {"text": "echo:foo", "replyActivityId": None, "recipientId": None, + "conversationName" : None, "locale": None, }), + (TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, {'text': 'bar', 'fromId': 'User1', 'conversationName': None, 'locale': None, + 'recipientId': 'bot', 'recipientName': 'user', 'fromName': 'user'}), + (TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, {'replyActivityId': None, 'recipientId': 'User1', 'conversationName': None, + 'locale': None, 'fromName': 'Bot', 'text': 'echo:bar'}), + ] + self.assert_telemetry_calls(telemetry, telemetry_calls) + + async def test_none_telemetry_client(self): + my_logger = TelemetryLoggerMiddleware(None, True) + + async def logic(context: TurnContext): + await context.send_activity(f'echo:{context.activity.text}') + + adapter = TestAdapter(logic) + adapter.use(my_logger) + test_flow = TestFlow(None, adapter) + test_flow = await test_flow.send('foo') + test_flow = await test_flow.assert_reply('echo:foo') + test_flow = await test_flow.send('bar') + await test_flow.assert_reply('echo:bar') + + async def test_log_update(self): + telemetry = Mock() + my_logger = TelemetryLoggerMiddleware(telemetry, True) + activity_to_update = None + + async def process(context: TurnContext) -> None: + nonlocal activity_to_update + if context.activity.text == 'update': + if not activity_to_update: + raise Exception('activity to update not set yet!') + activity_to_update.text = 'new response' + await context.update_activity(activity_to_update) + else: + activity = self.create_reply(context.activity, 'response') + response = await context.send_activity(activity) + activity.id = response.id + # clone the activity, so we can use it to do an update + activity_to_update = copy.copy(activity) + #await context.send_activity(f'echo:{context.activity.text}') + + adapter = TestAdapter(process) + adapter.use(my_logger) + test_flow = TestFlow(None, adapter) + test_flow = await test_flow.send('foo') + test_flow = await test_flow.assert_reply('response') + test_flow = await test_flow.send('update') + + # assert + # Note: None values just check for existence of the key, not the explicit + # value (generated) + telemetry_call_expected = [ + (TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, {"text":"foo", "fromId": "User1", "conversationName": None, "locale":None, + "recipientId" : "bot", "recipientName": 'user', }), + (TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, {'replyActivityId': '1', 'recipientId': 'User1', 'conversationName': None, + 'locale': None, 'fromName': 'Bot', 'text': 'response'}), + (TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, {'text': 'update', 'fromId': 'User1', 'conversationName': None, 'locale': None, + 'recipientId': 'bot', 'recipientName': 'user', 'fromName': 'user'}), + (TelemetryLoggerConstants.BOT_MSG_UPDATE_EVENT, {'recipientId': 'User1', 'conversationId': 'Convo1', 'conversationName': None, + 'locale': None, 'text': 'new response'}), + ] + self.assert_telemetry_calls(telemetry, telemetry_call_expected) + + def create_reply(self, activity, text, locale=None): + return Activity( + type=ActivityTypes.message, + from_property=ChannelAccount(id=activity.recipient.id, name=activity.recipient.name), + recipient=ChannelAccount(id=activity.from_property.id, name=activity.from_property.name), + reply_to_id=activity.id, + service_url=activity.service_url, + channel_id=activity.channel_id, + conversation=ConversationAccount(is_group=activity.conversation.is_group, id=activity.conversation.id, name=activity.conversation.name), + text=text or '', + locale=locale or activity.locale) + + def assert_telemetry_call(self, telemetry_mock, index: int, event_name: str,\ + props: Dict[str, str]) -> None: + # pylint: disable=unused-variable + + if index > len(telemetry_mock.track_event.call_args_list) - 1: + self.assertTrue(False, f'{len(telemetry_mock.track_event.call_args_list)} calls were made. You were asking for index {index}.') + args, kwargs = telemetry_mock.track_event.call_args_list[index] + self.assertEqual(args[0], event_name, f'Event NAME not matching.\n Expected: {props}\n Generated: {args[1]}') + + for key, val in props.items(): + self.assertTrue( + key in args[1], + msg=f"Could not find value {key} in '{args[1]}' for index {index}", + ) + self.assertTrue(isinstance(args[1], dict), f'ERROR: Second parm passed not a dictionary! {type(args[1])}') + if props[key]: + self.assertTrue(val == args[1][key], f' ERROR: Validate failed: "{val}" expected, "{args[1][key]}" generated') + + def assert_telemetry_calls(self, telemetry_mock, calls) -> None: + index = 0 + for event_name, props in calls: + self.assert_telemetry_call(telemetry_mock, index, event_name, props) + index += 1 + if index != len(telemetry_mock.track_event.call_args_list): + self.assertTrue( # pylint: disable=redundant-unittest-assert + False, + f"Found {len(telemetry_mock.track_event.call_args_list)} calls, testing for {index + 1}", + ) From d007709f0a24a93f903161c8a87231c4fa64076b Mon Sep 17 00:00:00 2001 From: Dave Taniguchi Date: Sat, 10 Aug 2019 15:27:50 -0700 Subject: [PATCH 2/5] Cleanup --- .../core/telemetry_logger_middleware.py | 19 +++++++++---------- .../tests/test_telemetry_middleware.py | 1 - 2 files changed, 9 insertions(+), 11 deletions(-) diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py index cc5ff5bf7..7a67a5e2d 100644 --- a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py @@ -3,16 +3,15 @@ """Middleware Component for logging Activity messages.""" from typing import Awaitable, Callable, List, Dict +from botbuilder.schema import Activity, ConversationReference, ActivityTypes from .bot_telemetry_client import BotTelemetryClient -from .bot_state import BotState from .bot_assert import BotAssert -from .bot_state_set import BotStateSet from .middleware_set import Middleware from .null_telemetry_client import NullTelemetryClient from .turn_context import TurnContext from .telemetry_constants import TelemetryConstants from .telemetry_logger_constants import TelemetryLoggerConstants -from botbuilder.schema import Activity, ConversationReference, ActivityTypes + # pylint: disable=line-too-long class TelemetryLoggerMiddleware(Middleware): @@ -34,7 +33,7 @@ def log_personal_information(self) -> bool: return self._log_personal_information async def on_process_request(self, context: TurnContext, - logic_fn: Callable[[TurnContext], Awaitable]) -> None: + logic_fn: Callable[[TurnContext], Awaitable]) -> None: """Logs events based on incoming and outgoing activities using BotTelemetryClient base class @@ -127,7 +126,7 @@ async def on_delete_activity(self, activity: Activity) -> None: await self.fill_delete_event_properties(activity)) - async def fill_receive_event_properties(self, activity: Activity, + async def fill_receive_event_properties(self, activity: Activity, additional_properties: Dict[str, str] = None) -> Dict[str, str]: """Fills the event properties for the BotMessageReceived. Adheres to the LogPersonalInformation flag to filter Name, Text and Speak properties. @@ -138,7 +137,7 @@ async def fill_receive_event_properties(self, activity: Activity, :return: A dictionary that is sent as "Properties" to BotTelemetryClient.track_event method for the BotMessageReceived event. """ - properties = { + properties = { TelemetryConstants.FROM_ID_PROPERTY : activity.from_property.id, TelemetryConstants.CONVERSATION_NAME_PROPERTY : activity.conversation.name, TelemetryConstants.LOCALE_PROPERTY : activity.locale, @@ -161,7 +160,7 @@ async def fill_receive_event_properties(self, activity: Activity, return properties - async def fill_send_event_properties(self, activity: Activity, + async def fill_send_event_properties(self, activity: Activity, additional_properties: Dict[str, str] = None) -> Dict[str, str]: """Fills the event properties for the BotMessageSend. These properties are logged when an activity message is sent by the Bot to the user. @@ -208,7 +207,7 @@ async def fill_update_event_properties(self, activity: Activity, :return: A dictionary that is sent as "Properties" to the BotTelemetryClient.track_event method for the BotMessageUpdate event. """ - properties = { + properties = { TelemetryConstants.RECIPIENT_ID_PROPERTY : activity.recipient.id, TelemetryConstants.CONVERSATION_ID_PROPERTY : activity.conversation.id, TelemetryConstants.CONVERSATION_NAME_PROPERTY : activity.conversation.name, @@ -227,7 +226,7 @@ async def fill_update_event_properties(self, activity: Activity, return properties - async def fill_delete_event_properties(self, activity: Activity, + async def fill_delete_event_properties(self, activity: Activity, additional_properties: Dict[str, str] = None) -> Dict[str, str]: """Fills the event properties for the BotMessageDelete. These properties are logged when an activity message is deleted by the Bot. @@ -238,7 +237,7 @@ async def fill_delete_event_properties(self, activity: Activity, :return: A dictionary that is sent as "Properties" to the BotTelemetryClient.track_event method for the BotMessageUpdate event. """ - properties = { + properties = { TelemetryConstants.RECIPIENT_ID_PROPERTY : activity.recipient.id, TelemetryConstants.CONVERSATION_ID_PROPERTY : activity.conversation.id, TelemetryConstants.CONVERSATION_NAME_PROPERTY : activity.conversation.name, diff --git a/libraries/botbuilder-core/tests/test_telemetry_middleware.py b/libraries/botbuilder-core/tests/test_telemetry_middleware.py index 89cd7f4e5..bad268cc0 100644 --- a/libraries/botbuilder-core/tests/test_telemetry_middleware.py +++ b/libraries/botbuilder-core/tests/test_telemetry_middleware.py @@ -1,7 +1,6 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License. -import sys import copy from typing import Awaitable, Callable, Dict import aiounittest From e451654cfbfb78be2b1ae8e24ab2e80e0962562a Mon Sep 17 00:00:00 2001 From: Dave Taniguchi Date: Mon, 12 Aug 2019 09:50:02 -0700 Subject: [PATCH 3/5] Black updates --- .../botbuilder/core/telemetry_constants.py | 28 +-- .../core/telemetry_logger_constants.py | 2 + .../core/telemetry_logger_middleware.py | 126 +++++++----- .../tests/test_telemetry_middleware.py | 189 +++++++++++++----- 4 files changed, 236 insertions(+), 109 deletions(-) diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py b/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py index 42e1390f2..148f606c6 100644 --- a/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py @@ -1,18 +1,20 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License + class TelemetryConstants(object): """Telemetry logger property names.""" - CHANNEL_ID_PROPERTY: str = 'channelId' - CONVERSATION_ID_PROPERTY: str = 'conversationId' - CONVERSATION_NAME_PROPERTY: str = 'conversationName' - DIALOG_ID_PROPERTY: str = 'dialogId' - FROM_ID_PROPERTY: str = 'fromId' - FROM_NAME_PROPERTY: str = 'fromName' - LOCALE_PROPERTY: str = 'locale' - RECIPIENT_ID_PROPERTY: str = 'recipientId' - RECIPIENT_NAME_PROPERTY: str = 'recipientName' - REPLY_ACTIVITY_ID_PROPERTY: str = 'replyActivityId' - TEXT_PROPERTY: str = 'text' - SPEAK_PROPERTY: str = 'speak' - USER_ID_PROPERTY: str = 'userId' + + CHANNEL_ID_PROPERTY: str = "channelId" + CONVERSATION_ID_PROPERTY: str = "conversationId" + CONVERSATION_NAME_PROPERTY: str = "conversationName" + DIALOG_ID_PROPERTY: str = "dialogId" + FROM_ID_PROPERTY: str = "fromId" + FROM_NAME_PROPERTY: str = "fromName" + LOCALE_PROPERTY: str = "locale" + RECIPIENT_ID_PROPERTY: str = "recipientId" + RECIPIENT_NAME_PROPERTY: str = "recipientName" + REPLY_ACTIVITY_ID_PROPERTY: str = "replyActivityId" + TEXT_PROPERTY: str = "text" + SPEAK_PROPERTY: str = "speak" + USER_ID_PROPERTY: str = "userId" diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py index f248abd2c..0817436c2 100644 --- a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py @@ -1,8 +1,10 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License + class TelemetryLoggerConstants(object): """The Telemetry Logger Event names.""" + # The name of the event when a new message is received from the user. BOT_MSG_RECEIVE_EVENT: str = "BotMessageReceived" diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py index 7a67a5e2d..0064bebd3 100644 --- a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py @@ -16,7 +16,10 @@ # pylint: disable=line-too-long class TelemetryLoggerMiddleware(Middleware): """Middleware for logging incoming, outgoing, updated or deleted Activity messages.""" - def __init__(self, telemetry_client: BotTelemetryClient, log_personal_information: bool) -> None: + + def __init__( + self, telemetry_client: BotTelemetryClient, log_personal_information: bool + ) -> None: super(TelemetryLoggerMiddleware, self).__init__() self._telemetry_client = telemetry_client or NullTelemetryClient() self._log_personal_information = log_personal_information @@ -32,8 +35,9 @@ def log_personal_information(self) -> bool: information that came from the user.""" return self._log_personal_information - async def on_process_request(self, context: TurnContext, - logic_fn: Callable[[TurnContext], Awaitable]) -> None: + async def on_process_request( + self, context: TurnContext, logic_fn: Callable[[TurnContext], Awaitable] + ) -> None: """Logs events based on incoming and outgoing activities using BotTelemetryClient base class @@ -52,8 +56,11 @@ async def on_process_request(self, context: TurnContext, # hook up onSend pipeline # pylint: disable=unused-argument - async def send_activities_handler(ctx: TurnContext, activities: List[Activity], - next_send: Callable[[], Awaitable[None]]): + async def send_activities_handler( + ctx: TurnContext, + activities: List[Activity], + next_send: Callable[[], Awaitable[None]], + ): # Run full pipeline responses = await next_send() for activity in activities: @@ -63,8 +70,9 @@ async def send_activities_handler(ctx: TurnContext, activities: List[Activity], context.on_send_activities(send_activities_handler) # hook up update activity pipeline - async def update_activity_handler(ctx: TurnContext, activity: Activity, - next_update: Callable[[], Awaitable]): + async def update_activity_handler( + ctx: TurnContext, activity: Activity, next_update: Callable[[], Awaitable] + ): # Run full pipeline response = await next_update() await self.on_update_activity(activity) @@ -73,14 +81,20 @@ async def update_activity_handler(ctx: TurnContext, activity: Activity, context.on_update_activity(update_activity_handler) # hook up delete activity pipeline - async def delete_activity_handler(ctx: TurnContext, reference: ConversationReference, - next_delete: Callable[[], Awaitable]): + async def delete_activity_handler( + ctx: TurnContext, + reference: ConversationReference, + next_delete: Callable[[], Awaitable], + ): # Run full pipeline await next_delete() - delete_msg = Activity(type=ActivityTypes.message_delete, - id=reference.activity_id) - deleted_activity: Activity = TurnContext.apply_conversation_reference(delete_msg, reference, False) + delete_msg = Activity( + type=ActivityTypes.message_delete, id=reference.activity_id + ) + deleted_activity: Activity = TurnContext.apply_conversation_reference( + delete_msg, reference, False + ) await self.on_delete_activity(deleted_activity) context.on_delete_activity(delete_activity_handler) @@ -88,15 +102,16 @@ async def delete_activity_handler(ctx: TurnContext, reference: ConversationRefer if logic_fn: await logic_fn() - async def on_receive_activity(self, activity: Activity) -> None: """Invoked when a message is received from the user. Performs logging of telemetry data using the BotTelemetryClient.track_event() method. This event name used is "BotMessageReceived". :param activity: Current activity sent from user. """ - self.telemetry_client.track_event(TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, - await self.fill_receive_event_properties(activity)) + self.telemetry_client.track_event( + TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, + await self.fill_receive_event_properties(activity), + ) async def on_send_activity(self, activity: Activity) -> None: """Invoked when the bot sends a message to the user. @@ -104,8 +119,10 @@ async def on_send_activity(self, activity: Activity) -> None: This event name used is "BotMessageSend". :param activity: Current activity sent from bot. """ - self.telemetry_client.track_event(TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, - await self.fill_send_event_properties(activity)) + self.telemetry_client.track_event( + TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, + await self.fill_send_event_properties(activity), + ) async def on_update_activity(self, activity: Activity) -> None: """Invoked when the bot updates a message. @@ -113,8 +130,10 @@ async def on_update_activity(self, activity: Activity) -> None: This event name used is "BotMessageUpdate". :param activity: Current activity sent from user. """ - self.telemetry_client.track_event(TelemetryLoggerConstants.BOT_MSG_UPDATE_EVENT, - await self.fill_update_event_properties(activity)) + self.telemetry_client.track_event( + TelemetryLoggerConstants.BOT_MSG_UPDATE_EVENT, + await self.fill_update_event_properties(activity), + ) async def on_delete_activity(self, activity: Activity) -> None: """Invoked when the bot deletes a message. @@ -122,12 +141,14 @@ async def on_delete_activity(self, activity: Activity) -> None: This event name used is "BotMessageDelete". :param activity: Current activity sent from user. """ - self.telemetry_client.track_event(TelemetryLoggerConstants.BOT_MSG_DELETE_EVENT, - await self.fill_delete_event_properties(activity)) - - - async def fill_receive_event_properties(self, activity: Activity, - additional_properties: Dict[str, str] = None) -> Dict[str, str]: + self.telemetry_client.track_event( + TelemetryLoggerConstants.BOT_MSG_DELETE_EVENT, + await self.fill_delete_event_properties(activity), + ) + + async def fill_receive_event_properties( + self, activity: Activity, additional_properties: Dict[str, str] = None + ) -> Dict[str, str]: """Fills the event properties for the BotMessageReceived. Adheres to the LogPersonalInformation flag to filter Name, Text and Speak properties. :param activity: activity sent from user. @@ -138,16 +159,18 @@ async def fill_receive_event_properties(self, activity: Activity, BotTelemetryClient.track_event method for the BotMessageReceived event. """ properties = { - TelemetryConstants.FROM_ID_PROPERTY : activity.from_property.id, - TelemetryConstants.CONVERSATION_NAME_PROPERTY : activity.conversation.name, - TelemetryConstants.LOCALE_PROPERTY : activity.locale, - TelemetryConstants.RECIPIENT_ID_PROPERTY : activity.recipient.id, - TelemetryConstants.RECIPIENT_NAME_PROPERTY : activity.from_property.name, + TelemetryConstants.FROM_ID_PROPERTY: activity.from_property.id, + TelemetryConstants.CONVERSATION_NAME_PROPERTY: activity.conversation.name, + TelemetryConstants.LOCALE_PROPERTY: activity.locale, + TelemetryConstants.RECIPIENT_ID_PROPERTY: activity.recipient.id, + TelemetryConstants.RECIPIENT_NAME_PROPERTY: activity.from_property.name, } if self.log_personal_information: if activity.from_property.name and activity.from_property.name.strip(): - properties[TelemetryConstants.FROM_NAME_PROPERTY] = activity.from_property.name + properties[ + TelemetryConstants.FROM_NAME_PROPERTY + ] = activity.from_property.name if activity.text and activity.text.strip(): properties[TelemetryConstants.TEXT_PROPERTY] = activity.text if activity.speak and activity.speak.strip(): @@ -160,8 +183,9 @@ async def fill_receive_event_properties(self, activity: Activity, return properties - async def fill_send_event_properties(self, activity: Activity, - additional_properties: Dict[str, str] = None) -> Dict[str, str]: + async def fill_send_event_properties( + self, activity: Activity, additional_properties: Dict[str, str] = None + ) -> Dict[str, str]: """Fills the event properties for the BotMessageSend. These properties are logged when an activity message is sent by the Bot to the user. :param activity: activity sent from user. @@ -172,16 +196,18 @@ async def fill_send_event_properties(self, activity: Activity, BotTelemetryClient.track_event method for the BotMessageSend event. """ properties = { - TelemetryConstants.REPLY_ACTIVITY_ID_PROPERTY : activity.reply_to_id, - TelemetryConstants.RECIPIENT_ID_PROPERTY : activity.recipient.id, - TelemetryConstants.CONVERSATION_NAME_PROPERTY : activity.conversation.name, - TelemetryConstants.LOCALE_PROPERTY : activity.locale, + TelemetryConstants.REPLY_ACTIVITY_ID_PROPERTY: activity.reply_to_id, + TelemetryConstants.RECIPIENT_ID_PROPERTY: activity.recipient.id, + TelemetryConstants.CONVERSATION_NAME_PROPERTY: activity.conversation.name, + TelemetryConstants.LOCALE_PROPERTY: activity.locale, } # Use the LogPersonalInformation flag to toggle logging PII data, text and user name are common examples if self.log_personal_information: if activity.from_property.name and activity.from_property.name.strip(): - properties[TelemetryConstants.FROM_NAME_PROPERTY] = activity.from_property.name + properties[ + TelemetryConstants.FROM_NAME_PROPERTY + ] = activity.from_property.name if activity.text and activity.text.strip(): properties[TelemetryConstants.TEXT_PROPERTY] = activity.text if activity.speak and activity.speak.strip(): @@ -194,8 +220,9 @@ async def fill_send_event_properties(self, activity: Activity, return properties - async def fill_update_event_properties(self, activity: Activity, - additional_properties: Dict[str, str] = None) -> Dict[str, str]: + async def fill_update_event_properties( + self, activity: Activity, additional_properties: Dict[str, str] = None + ) -> Dict[str, str]: """Fills the event properties for the BotMessageUpdate. These properties are logged when an activity message is updated by the Bot. For example, if a card is interacted with by the use, and the card needs @@ -208,10 +235,10 @@ async def fill_update_event_properties(self, activity: Activity, BotTelemetryClient.track_event method for the BotMessageUpdate event. """ properties = { - TelemetryConstants.RECIPIENT_ID_PROPERTY : activity.recipient.id, - TelemetryConstants.CONVERSATION_ID_PROPERTY : activity.conversation.id, - TelemetryConstants.CONVERSATION_NAME_PROPERTY : activity.conversation.name, - TelemetryConstants.LOCALE_PROPERTY : activity.locale, + TelemetryConstants.RECIPIENT_ID_PROPERTY: activity.recipient.id, + TelemetryConstants.CONVERSATION_ID_PROPERTY: activity.conversation.id, + TelemetryConstants.CONVERSATION_NAME_PROPERTY: activity.conversation.name, + TelemetryConstants.LOCALE_PROPERTY: activity.locale, } # Use the LogPersonalInformation flag to toggle logging PII data, text is a common examples @@ -226,8 +253,9 @@ async def fill_update_event_properties(self, activity: Activity, return properties - async def fill_delete_event_properties(self, activity: Activity, - additional_properties: Dict[str, str] = None) -> Dict[str, str]: + async def fill_delete_event_properties( + self, activity: Activity, additional_properties: Dict[str, str] = None + ) -> Dict[str, str]: """Fills the event properties for the BotMessageDelete. These properties are logged when an activity message is deleted by the Bot. :param activity: activity sent from user. @@ -238,9 +266,9 @@ async def fill_delete_event_properties(self, activity: Activity, BotTelemetryClient.track_event method for the BotMessageUpdate event. """ properties = { - TelemetryConstants.RECIPIENT_ID_PROPERTY : activity.recipient.id, - TelemetryConstants.CONVERSATION_ID_PROPERTY : activity.conversation.id, - TelemetryConstants.CONVERSATION_NAME_PROPERTY : activity.conversation.name, + TelemetryConstants.RECIPIENT_ID_PROPERTY: activity.recipient.id, + TelemetryConstants.CONVERSATION_ID_PROPERTY: activity.conversation.id, + TelemetryConstants.CONVERSATION_NAME_PROPERTY: activity.conversation.name, } # Additional properties can override "stock" properties diff --git a/libraries/botbuilder-core/tests/test_telemetry_middleware.py b/libraries/botbuilder-core/tests/test_telemetry_middleware.py index bad268cc0..7c4c746d7 100644 --- a/libraries/botbuilder-core/tests/test_telemetry_middleware.py +++ b/libraries/botbuilder-core/tests/test_telemetry_middleware.py @@ -25,41 +25,77 @@ ConversationReference, ) -#pylint: disable=line-too-long,missing-docstring +# pylint: disable=line-too-long,missing-docstring class TestTelemetryMiddleware(aiounittest.AsyncTestCase): # pylint: disable=unused-argument async def test_create_middleware(self): telemetry = NullTelemetryClient() my_logger = TelemetryLoggerMiddleware(telemetry, True) - assert(my_logger) + assert my_logger async def test_should_send_receive(self): telemetry = Mock() my_logger = TelemetryLoggerMiddleware(telemetry, True) async def logic(context: TurnContext): - await context.send_activity(f'echo:{context.activity.text}') + await context.send_activity(f"echo:{context.activity.text}") adapter = TestAdapter(logic) adapter.use(my_logger) test_flow = TestFlow(None, adapter) - test_flow = await test_flow.send('foo') - test_flow = await test_flow.assert_reply('echo:foo') - test_flow = await test_flow.send('bar') - await test_flow.assert_reply('echo:bar') + test_flow = await test_flow.send("foo") + test_flow = await test_flow.assert_reply("echo:foo") + test_flow = await test_flow.send("bar") + await test_flow.assert_reply("echo:bar") # assert # Note: None values just check for existence of the key, not the explicit # value (generated) telemetry_calls = [ - (TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, {"text":"foo", "fromId": "User1", "conversationName": None, "locale":None, - "recipientId" : "bot", "recipientName": 'user', }), - (TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, {"text": "echo:foo", "replyActivityId": None, "recipientId": None, - "conversationName" : None, "locale": None, }), - (TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, {'text': 'bar', 'fromId': 'User1', 'conversationName': None, 'locale': None, - 'recipientId': 'bot', 'recipientName': 'user', 'fromName': 'user'}), - (TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, {'replyActivityId': None, 'recipientId': 'User1', 'conversationName': None, - 'locale': None, 'fromName': 'Bot', 'text': 'echo:bar'}), + ( + TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, + { + "text": "foo", + "fromId": "User1", + "conversationName": None, + "locale": None, + "recipientId": "bot", + "recipientName": "user", + }, + ), + ( + TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, + { + "text": "echo:foo", + "replyActivityId": None, + "recipientId": None, + "conversationName": None, + "locale": None, + }, + ), + ( + TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, + { + "text": "bar", + "fromId": "User1", + "conversationName": None, + "locale": None, + "recipientId": "bot", + "recipientName": "user", + "fromName": "user", + }, + ), + ( + TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, + { + "replyActivityId": None, + "recipientId": "User1", + "conversationName": None, + "locale": None, + "fromName": "Bot", + "text": "echo:bar", + }, + ), ] self.assert_telemetry_calls(telemetry, telemetry_calls) @@ -67,15 +103,15 @@ async def test_none_telemetry_client(self): my_logger = TelemetryLoggerMiddleware(None, True) async def logic(context: TurnContext): - await context.send_activity(f'echo:{context.activity.text}') + await context.send_activity(f"echo:{context.activity.text}") adapter = TestAdapter(logic) adapter.use(my_logger) test_flow = TestFlow(None, adapter) - test_flow = await test_flow.send('foo') - test_flow = await test_flow.assert_reply('echo:foo') - test_flow = await test_flow.send('bar') - await test_flow.assert_reply('echo:bar') + test_flow = await test_flow.send("foo") + test_flow = await test_flow.assert_reply("echo:foo") + test_flow = await test_flow.send("bar") + await test_flow.assert_reply("echo:bar") async def test_log_update(self): telemetry = Mock() @@ -84,70 +120,129 @@ async def test_log_update(self): async def process(context: TurnContext) -> None: nonlocal activity_to_update - if context.activity.text == 'update': + if context.activity.text == "update": if not activity_to_update: - raise Exception('activity to update not set yet!') - activity_to_update.text = 'new response' + raise Exception("activity to update not set yet!") + activity_to_update.text = "new response" await context.update_activity(activity_to_update) else: - activity = self.create_reply(context.activity, 'response') + activity = self.create_reply(context.activity, "response") response = await context.send_activity(activity) activity.id = response.id # clone the activity, so we can use it to do an update activity_to_update = copy.copy(activity) - #await context.send_activity(f'echo:{context.activity.text}') + # await context.send_activity(f'echo:{context.activity.text}') adapter = TestAdapter(process) adapter.use(my_logger) test_flow = TestFlow(None, adapter) - test_flow = await test_flow.send('foo') - test_flow = await test_flow.assert_reply('response') - test_flow = await test_flow.send('update') + test_flow = await test_flow.send("foo") + test_flow = await test_flow.assert_reply("response") + test_flow = await test_flow.send("update") # assert # Note: None values just check for existence of the key, not the explicit # value (generated) telemetry_call_expected = [ - (TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, {"text":"foo", "fromId": "User1", "conversationName": None, "locale":None, - "recipientId" : "bot", "recipientName": 'user', }), - (TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, {'replyActivityId': '1', 'recipientId': 'User1', 'conversationName': None, - 'locale': None, 'fromName': 'Bot', 'text': 'response'}), - (TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, {'text': 'update', 'fromId': 'User1', 'conversationName': None, 'locale': None, - 'recipientId': 'bot', 'recipientName': 'user', 'fromName': 'user'}), - (TelemetryLoggerConstants.BOT_MSG_UPDATE_EVENT, {'recipientId': 'User1', 'conversationId': 'Convo1', 'conversationName': None, - 'locale': None, 'text': 'new response'}), + ( + TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, + { + "text": "foo", + "fromId": "User1", + "conversationName": None, + "locale": None, + "recipientId": "bot", + "recipientName": "user", + }, + ), + ( + TelemetryLoggerConstants.BOT_MSG_SEND_EVENT, + { + "replyActivityId": "1", + "recipientId": "User1", + "conversationName": None, + "locale": None, + "fromName": "Bot", + "text": "response", + }, + ), + ( + TelemetryLoggerConstants.BOT_MSG_RECEIVE_EVENT, + { + "text": "update", + "fromId": "User1", + "conversationName": None, + "locale": None, + "recipientId": "bot", + "recipientName": "user", + "fromName": "user", + }, + ), + ( + TelemetryLoggerConstants.BOT_MSG_UPDATE_EVENT, + { + "recipientId": "User1", + "conversationId": "Convo1", + "conversationName": None, + "locale": None, + "text": "new response", + }, + ), ] self.assert_telemetry_calls(telemetry, telemetry_call_expected) def create_reply(self, activity, text, locale=None): return Activity( type=ActivityTypes.message, - from_property=ChannelAccount(id=activity.recipient.id, name=activity.recipient.name), - recipient=ChannelAccount(id=activity.from_property.id, name=activity.from_property.name), + from_property=ChannelAccount( + id=activity.recipient.id, name=activity.recipient.name + ), + recipient=ChannelAccount( + id=activity.from_property.id, name=activity.from_property.name + ), reply_to_id=activity.id, service_url=activity.service_url, channel_id=activity.channel_id, - conversation=ConversationAccount(is_group=activity.conversation.is_group, id=activity.conversation.id, name=activity.conversation.name), - text=text or '', - locale=locale or activity.locale) + conversation=ConversationAccount( + is_group=activity.conversation.is_group, + id=activity.conversation.id, + name=activity.conversation.name, + ), + text=text or "", + locale=locale or activity.locale, + ) - def assert_telemetry_call(self, telemetry_mock, index: int, event_name: str,\ - props: Dict[str, str]) -> None: + def assert_telemetry_call( + self, telemetry_mock, index: int, event_name: str, props: Dict[str, str] + ) -> None: # pylint: disable=unused-variable if index > len(telemetry_mock.track_event.call_args_list) - 1: - self.assertTrue(False, f'{len(telemetry_mock.track_event.call_args_list)} calls were made. You were asking for index {index}.') + self.assertTrue( + False, + f"{len(telemetry_mock.track_event.call_args_list)} calls were made. You were asking for index {index}.", + ) args, kwargs = telemetry_mock.track_event.call_args_list[index] - self.assertEqual(args[0], event_name, f'Event NAME not matching.\n Expected: {props}\n Generated: {args[1]}') + self.assertEqual( + args[0], + event_name, + f"Event NAME not matching.\n Expected: {props}\n Generated: {args[1]}", + ) for key, val in props.items(): self.assertTrue( key in args[1], msg=f"Could not find value {key} in '{args[1]}' for index {index}", ) - self.assertTrue(isinstance(args[1], dict), f'ERROR: Second parm passed not a dictionary! {type(args[1])}') + self.assertTrue( + isinstance(args[1], dict), + f"ERROR: Second parm passed not a dictionary! {type(args[1])}", + ) if props[key]: - self.assertTrue(val == args[1][key], f' ERROR: Validate failed: "{val}" expected, "{args[1][key]}" generated') + self.assertTrue( + val == args[1][key], + f' ERROR: Validate failed: "{val}" expected, "{args[1][key]}" generated', + ) def assert_telemetry_calls(self, telemetry_mock, calls) -> None: index = 0 From 4d88ca1c47bf486879a78242fd115d69e52734c0 Mon Sep 17 00:00:00 2001 From: Dave Taniguchi Date: Mon, 12 Aug 2019 13:55:41 -0700 Subject: [PATCH 4/5] pylint updates --- .../botbuilder/core/telemetry_constants.py | 2 +- .../core/telemetry_logger_constants.py | 2 +- .../core/telemetry_logger_middleware.py | 1 + .../tests/test_telemetry_middleware.py | 24 +++++++------------ 4 files changed, 11 insertions(+), 18 deletions(-) diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py b/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py index 148f606c6..be5b37f77 100644 --- a/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py @@ -2,7 +2,7 @@ # Licensed under the MIT License -class TelemetryConstants(object): +class TelemetryConstants(): """Telemetry logger property names.""" CHANNEL_ID_PROPERTY: str = "channelId" diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py index 0817436c2..2384b211d 100644 --- a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py @@ -2,7 +2,7 @@ # Licensed under the MIT License -class TelemetryLoggerConstants(object): +class TelemetryLoggerConstants(): """The Telemetry Logger Event names.""" # The name of the event when a new message is received from the user. diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py index 0064bebd3..cdb7fcca5 100644 --- a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_middleware.py @@ -35,6 +35,7 @@ def log_personal_information(self) -> bool: information that came from the user.""" return self._log_personal_information + # pylint: disable=arguments-differ async def on_process_request( self, context: TurnContext, logic_fn: Callable[[TurnContext], Awaitable] ) -> None: diff --git a/libraries/botbuilder-core/tests/test_telemetry_middleware.py b/libraries/botbuilder-core/tests/test_telemetry_middleware.py index 7c4c746d7..7128dab8d 100644 --- a/libraries/botbuilder-core/tests/test_telemetry_middleware.py +++ b/libraries/botbuilder-core/tests/test_telemetry_middleware.py @@ -1,16 +1,12 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License. +# pylint: disable=line-too-long,missing-docstring,unused-variable import copy -from typing import Awaitable, Callable, Dict +from typing import Dict +from unittest.mock import Mock import aiounittest - -from unittest.mock import patch, Mock from botbuilder.core import ( - AnonymousReceiveMiddleware, - BotTelemetryClient, - MiddlewareSet, - Middleware, NullTelemetryClient, TelemetryLoggerMiddleware, TelemetryLoggerConstants, @@ -22,10 +18,9 @@ ActivityTypes, ChannelAccount, ConversationAccount, - ConversationReference, ) -# pylint: disable=line-too-long,missing-docstring + class TestTelemetryMiddleware(aiounittest.AsyncTestCase): # pylint: disable=unused-argument async def test_create_middleware(self): @@ -215,13 +210,10 @@ def create_reply(self, activity, text, locale=None): def assert_telemetry_call( self, telemetry_mock, index: int, event_name: str, props: Dict[str, str] ) -> None: - # pylint: disable=unused-variable - - if index > len(telemetry_mock.track_event.call_args_list) - 1: - self.assertTrue( - False, - f"{len(telemetry_mock.track_event.call_args_list)} calls were made. You were asking for index {index}.", - ) + self.assertTrue( + index < len(telemetry_mock.track_event.call_args_list), + f"{len(telemetry_mock.track_event.call_args_list)} calls were made. You were asking for index {index}.", + ) args, kwargs = telemetry_mock.track_event.call_args_list[index] self.assertEqual( args[0], From 4cd523a6c8bd3855e1fa5a8a584582cf4297af1d Mon Sep 17 00:00:00 2001 From: Dave Taniguchi Date: Mon, 12 Aug 2019 14:04:19 -0700 Subject: [PATCH 5/5] Black stuff --- .../botbuilder-core/botbuilder/core/telemetry_constants.py | 2 +- .../botbuilder/core/telemetry_logger_constants.py | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py b/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py index be5b37f77..1ae0f1816 100644 --- a/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_constants.py @@ -2,7 +2,7 @@ # Licensed under the MIT License -class TelemetryConstants(): +class TelemetryConstants: """Telemetry logger property names.""" CHANNEL_ID_PROPERTY: str = "channelId" diff --git a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py index 2384b211d..486c502b5 100644 --- a/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py +++ b/libraries/botbuilder-core/botbuilder/core/telemetry_logger_constants.py @@ -2,7 +2,7 @@ # Licensed under the MIT License -class TelemetryLoggerConstants(): +class TelemetryLoggerConstants: """The Telemetry Logger Event names.""" # The name of the event when a new message is received from the user.