From 8400c581151cf4898c93a9748166597ee8c38434 Mon Sep 17 00:00:00 2001 From: Rodrigo Brandao Date: Mon, 2 Nov 2026 11:53:30 -0800 Subject: [PATCH 1/2] Lazy formatting of log messages --- .../authentication/msal/msal_auth.py | 21 +++-- .../copilotstudio/client/copilot_client.py | 15 ++-- .../hosting/core/app/agent_application.py | 78 ++++++++++++++----- .../_handlers/connector_user_authorization.py | 6 +- .../core/app/streaming/streaming_response.py | 2 +- 5 files changed, 83 insertions(+), 39 deletions(-) diff --git a/libraries/microsoft-agents-authentication-msal/microsoft_agents/authentication/msal/msal_auth.py b/libraries/microsoft-agents-authentication-msal/microsoft_agents/authentication/msal/msal_auth.py index 15f54afa8..86eca6635 100644 --- a/libraries/microsoft-agents-authentication-msal/microsoft_agents/authentication/msal/msal_auth.py +++ b/libraries/microsoft-agents-authentication-msal/microsoft_agents/authentication/msal/msal_auth.py @@ -63,7 +63,7 @@ def __init__(self, msal_configuration: AgentAuthConfiguration): # TokenCache is thread-safe and async-safe per MSAL documentation self._token_cache = TokenCache() logger.debug( - f"Initializing MsalAuth with configuration: {self._msal_configuration}" + "Initializing MsalAuth with configuration: %s", self._msal_configuration ) @property @@ -115,7 +115,9 @@ async def _get_access_token( self._msal_configuration.AUTH_TYPE, ): logger.debug( - f"Requesting access token for resource: {resource_url}, scopes: {scopes}" + "Requesting access token for resource: %s, scopes: %s", + resource_url, + scopes, ) valid_uri, instance_uri = self._uri_validator(resource_url) if not valid_uri: @@ -191,7 +193,7 @@ async def acquire_token_on_behalf_of( ) if "access_token" not in token: - logger.error(f"Failed to acquire token on behalf of user.") + logger.error("Failed to acquire token on behalf of user.") raise ValueError( authentication_errors.FailedToAcquireToken.format(str(token)) ) @@ -199,7 +201,8 @@ async def acquire_token_on_behalf_of( return token["access_token"] logger.error( - f"On-behalf-of flow is not supported with the current authentication type: {msal_auth_client.__class__.__name__}" + "On-behalf-of flow is not supported with the current authentication type: %s", + msal_auth_client.__class__.__name__, ) raise NotImplementedError( authentication_errors.OnBehalfOfFlowNotSupportedAuthType.format( @@ -322,7 +325,8 @@ def get_assertion() -> str: ) if "access_token" not in result: logger.error( - f"Failed to acquire token for federated credentials: {result}" + "Failed to acquire token for federated credentials: %s", + result, ) raise ValueError( authentication_errors.FailedToAcquireToken.format( @@ -347,7 +351,8 @@ def get_assertion() -> str: client_credential = {"client_assertion": get_assertion} else: logger.error( - f"Unsupported authentication type: {self._msal_configuration.AUTH_TYPE}" + "Unsupported authentication type: %s", + self._msal_configuration.AUTH_TYPE, ) raise NotImplementedError( str(authentication_errors.AuthenticationTypeNotSupported) @@ -385,7 +390,7 @@ def _uri_validator(url_str: str) -> tuple[bool, Optional[URI]]: result = urlparse(url_str) return all([result.scheme, result.netloc]), result except AttributeError: - logger.error(f"URI parsing error for {url_str}") + logger.error("URI parsing error for %s", url_str) return False, None def _resolve_scopes_list(self, instance_url: URI, scopes=None) -> list[str]: @@ -401,7 +406,7 @@ def _resolve_scopes_list(self, instance_url: URI, scopes=None) -> list[str]: "{instance}", f"{instance_url.scheme}://{instance_url.hostname}" ) temp_list.append(scope_placeholder) - logger.debug(f"Resolved scopes: {temp_list}") + logger.debug("Resolved scopes: %s", temp_list) return temp_list # the call to MSAL is blocking, but in the future we want to create an asyncio task diff --git a/libraries/microsoft-agents-copilotstudio-client/microsoft_agents/copilotstudio/client/copilot_client.py b/libraries/microsoft-agents-copilotstudio-client/microsoft_agents/copilotstudio/client/copilot_client.py index 2994f1906..8e69e359a 100644 --- a/libraries/microsoft-agents-copilotstudio-client/microsoft_agents/copilotstudio/client/copilot_client.py +++ b/libraries/microsoft-agents-copilotstudio-client/microsoft_agents/copilotstudio/client/copilot_client.py @@ -145,7 +145,7 @@ async def post_request( # Log diagnostic information if enabled if self.settings.enable_diagnostics: - self._logger.debug(f">>> SEND TO {url}") + self._logger.debug(">>> SEND TO %s", url) async with aiohttp.ClientSession( **self.settings.client_session_settings @@ -153,7 +153,7 @@ async def post_request( async with session.post(url, json=data, headers=headers) as response: if response.status != 200: - self._logger.error(f"Error sending request: {response.status}") + self._logger.error("Error sending request: %s", response.status) raise aiohttp.ClientError( f"Error sending request: {response.status}" ) @@ -162,7 +162,7 @@ async def post_request( if self.settings.enable_diagnostics: self._logger.debug("=" * 53) for header_key, header_value in response.headers.items(): - self._logger.debug(f"{header_key} = {header_value}") + self._logger.debug("%s = %s", header_key, header_value) self._logger.debug("=" * 53) # Capture experimental endpoint if enabled and not already using DirectConnect @@ -177,7 +177,8 @@ async def post_request( self._island_experimental_url = experimental_url self.settings.direct_connect_url = self._island_experimental_url self._logger.debug( - f"Island Experimental URL: {self._island_experimental_url}" + "Island Experimental URL: %s", + self._island_experimental_url, ) # Set conversation ID from response header when status is 200 @@ -354,7 +355,7 @@ async def subscribe( # Log diagnostic information if enabled if self.settings.enable_diagnostics: - self._logger.debug(f">>> SEND TO {url}") + self._logger.debug(">>> SEND TO %s", url) async with aiohttp.ClientSession( **self.settings.client_session_settings @@ -363,7 +364,7 @@ async def subscribe( if response.status != 200: self._logger.error( - f"Error subscribing to conversation: {response.status}" + "Error subscribing to conversation: %s", response.status ) raise aiohttp.ClientError( f"Error subscribing to conversation: {response.status}" @@ -373,7 +374,7 @@ async def subscribe( if self.settings.enable_diagnostics: self._logger.debug("=" * 53) for header_key, header_value in response.headers.items(): - self._logger.debug(f"{header_key} = {header_value}") + self._logger.debug("%s = %s", header_key, header_value) self._logger.debug("=" * 53) event_id = None diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/agent_application.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/agent_application.py index c3802357f..49aa83b38 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/agent_application.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/agent_application.py @@ -421,7 +421,10 @@ async def on_event(context: TurnContext, state: TurnState): def __call(func: RouteHandler[StateT]) -> RouteHandler[StateT]: logger.debug( - f"Registering activity handler for route handler {func.__name__} with type: {activity_type} with auth handlers: {auth_handlers}" + "Registering activity handler for route handler %s with type: %s with auth handlers: %s", + func.__name__, + activity_type, + auth_handlers, ) self.add_route(selector, func, auth_handlers=auth_handlers, **kwargs) return func @@ -481,7 +484,10 @@ def event( def __call(func: RouteHandler[StateT]) -> RouteHandler[StateT]: logger.debug( - f"Registering event handler for route handler {func.__name__} with select: {select} with auth handlers: {auth_handlers}" + "Registering event handler for route handler %s with select: %s with auth handlers: %s", + func.__name__, + select, + auth_handlers, ) self.add_route(selector, func, auth_handlers=auth_handlers, **kwargs) return func @@ -523,7 +529,10 @@ def invoke( def __call(func: RouteHandler[StateT]) -> RouteHandler[StateT]: logger.debug( - f"Registering invoke handler for route handler {func.__name__} with select: {select} with auth handlers: {auth_handlers}" + "Registering invoke handler for route handler %s with select: %s with auth handlers: %s", + func.__name__, + select, + auth_handlers, ) self.add_route( selector, func, auth_handlers=auth_handlers, is_invoke=True, **kwargs @@ -570,7 +579,10 @@ async def on_hi_message(context: TurnContext, state: TurnState): def __call(func: RouteHandler[StateT]) -> RouteHandler[StateT]: logger.debug( - f"Registering message handler for route handler {func.__name__} with select: {select} with auth handlers: {auth_handlers}" + "Registering message handler for route handler %s with select: %s with auth handlers: %s", + func.__name__, + select, + auth_handlers, ) self.add_route(selector, func, auth_handlers=auth_handlers, **kwargs) return func @@ -634,7 +646,10 @@ def __selector(context: TurnContext): def __call(func: RouteHandler[StateT]) -> RouteHandler[StateT]: logger.debug( - f"Registering conversation update handler for route handler {func.__name__} with type: {update_type} with auth handlers: {auth_handlers}" + "Registering conversation update handler for route handler %s with type: %s with auth handlers: %s", + func.__name__, + update_type, + auth_handlers, ) self.add_route(__selector, func, auth_handlers=auth_handlers, **kwargs) return func @@ -763,7 +778,10 @@ def __selector(context: TurnContext): def __call(func: RouteHandler[StateT]) -> RouteHandler[StateT]: logger.debug( - f"Registering message reaction handler for route handler {func.__name__} with type: {reaction_type} with auth handlers: {auth_handlers}" + "Registering message reaction handler for route handler %s with type: %s with auth handlers: %s", + func.__name__, + reaction_type, + auth_handlers, ) self.add_route(__selector, func, auth_handlers=auth_handlers, **kwargs) return func @@ -880,7 +898,10 @@ def __selector(context: TurnContext): def __call(func: RouteHandler[StateT]) -> RouteHandler[StateT]: logger.debug( - f"Registering message update handler for route handler {func.__name__} with type: {update_type} with auth handlers: {auth_handlers}" + "Registering message update handler for route handler %s with type: %s with auth handlers: %s", + func.__name__, + update_type, + auth_handlers, ) self.add_route(__selector, func, auth_handlers=auth_handlers, **kwargs) return func @@ -961,7 +982,9 @@ async def __handler(context: TurnContext, state: StateT): ) logger.debug( - f"Registering handoff handler for route handler {func.__name__} with auth handlers: {auth_handlers}" + "Registering handoff handler for route handler %s with auth handlers: %s", + func.__name__, + auth_handlers, ) self.add_route(selector, __handler, auth_handlers=auth_handlers, **kwargs) @@ -991,12 +1014,14 @@ async def sign_in_success(context: TurnContext, state: TurnState, connection_id: if self._auth: logger.debug( - f"Registering sign-in success handler for route handler {func.__name__}" + "Registering sign-in success handler for route handler %s", + func.__name__, ) self._auth.on_sign_in_success(func) else: logger.error( - f"Failed to register sign-in success handler for route handler {func.__name__}", + "Failed to register sign-in success handler for route handler %s", + func.__name__, stack_info=True, ) raise ApplicationError(""" @@ -1025,12 +1050,14 @@ async def sign_in_failure(context: TurnContext, state: TurnState, connection_id: if self._auth: logger.debug( - f"Registering sign-in failure handler for route handler {func.__name__}" + "Registering sign-in failure handler for route handler %s", + func.__name__, ) self._auth.on_sign_in_failure(func) else: logger.error( - f"Failed to register sign-in failure handler for route handler {func.__name__}", + "Failed to register sign-in failure handler for route handler %s", + func.__name__, stack_info=True, ) raise ApplicationError(""" @@ -1056,7 +1083,7 @@ async def on_error(context: TurnContext, err: Exception): :type func: Callable[[TurnContext, Exception], Awaitable[None]] """ - logger.debug(f"Registering the error handler {func.__name__} ") + logger.debug("Registering the error handler %s ", func.__name__) self._turn_error_handlers.append(func) return func @@ -1065,13 +1092,14 @@ def set_turn_state_factory(self, func: Callable[[], StateT]): """ Custom Turn State Factory """ - logger.debug(f"Setting custom turn state factory: {func.__name__}") + logger.debug("Setting custom turn state factory: %s", func.__name__) self._turn_state_factory = func return func async def on_turn(self, context: TurnContext): logger.debug( - f"AgentApplication.on_turn(): Processing turn for context: {context.activity.id}" + "AgentApplication.on_turn(): Processing turn for context: %s", + context.activity.id, ) await self._start_long_running_call(context, self._on_turn) @@ -1179,7 +1207,8 @@ async def _handle_file_downloads(self, context: TurnContext, state: StateT): input_files = state.temp.input_files if state.temp.input_files else [] for file_downloader in self._options.file_downloaders: logger.info( - f"Using file downloader: {file_downloader.__class__.__name__}" + "Using file downloader: %s", + file_downloader.__class__.__name__, ) files = await file_downloader.download_files(context) input_files.extend(files) @@ -1237,7 +1266,9 @@ async def _on_activity( if not route_matched: logger.warning( - f"No route found for activity type: {context.activity.type} with text: {context.activity.text}" + "No route found for activity type: %s with text: %s", + context.activity.type, + context.activity.text, ) if on_turn_span is not None: on_turn_span.share( @@ -1254,7 +1285,9 @@ async def _start_long_running_call( and context.identity is not None ): logger.debug( - f"Starting long running call for context: {context.activity.id} with function: {func.__name__}" + "Starting long running call for context: %s with function: %s", + context.activity.id, + func.__name__, ) return await context.adapter.continue_conversation_with_claims( claims_identity=context.identity, @@ -1290,7 +1323,7 @@ def __log_task_result(task: asyncio.Task): task.result() except Exception as e: logger.error( - f"Error occurred while replaying the turn.", + "Error occurred while replaying the turn.", exc_info=True, ) @@ -1327,12 +1360,15 @@ async def _on_error(self, context: TurnContext, err: Exception) -> None: """ logger.error( - f"An error occurred in the AgentApplication: {err}", + "An error occurred in the AgentApplication: %s", + err, exc_info=True, ) for err_func in self._turn_error_handlers: - logger.info(f"Calling error handler {err_func.__name__} for error: {err}") + logger.info( + "Calling error handler %s for error: %s", err_func.__name__, err + ) await err_func(context, err) if not self._turn_error_handlers: diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/oauth/_handlers/connector_user_authorization.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/oauth/_handlers/connector_user_authorization.py index 0e57433a0..523ee9bff 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/oauth/_handlers/connector_user_authorization.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/oauth/_handlers/connector_user_authorization.py @@ -119,7 +119,9 @@ async def get_refreshed_token( ) except (ValueError, AttributeError) as ex: logger.error( - f"Error checking token expiration for handler {self._id}: {ex}" + "Error checking token expiration for handler %s: %s", + self._id, + ex, ) raise @@ -234,7 +236,7 @@ def _create_token_response(self, context: TurnContext) -> TokenResponse: token_response.expiration = expiration.isoformat() except Exception as ex: - logger.warning(f"Failed to parse JWT token for handler {self._id}: {ex}") + logger.warning("Failed to parse JWT token for handler %s: %s", self._id, ex) raise ex return token_response diff --git a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/streaming/streaming_response.py b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/streaming/streaming_response.py index d2bdef9b0..c8e327e98 100644 --- a/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/streaming/streaming_response.py +++ b/libraries/microsoft-agents-hosting-core/microsoft_agents/hosting/core/app/streaming/streaming_response.py @@ -468,7 +468,7 @@ async def _drain_queue(self) -> None: Sends any queued activities to the client until the queue is empty. """ try: - logger.debug(f"Draining queue with {len(self._queue)} activities.") + logger.debug("Draining queue with %s activities.", len(self._queue)) while self._queue: factory = self._queue.pop(0) activity = factory() From a506a7f5ed5c71131910445eb86c4b5fad1043f6 Mon Sep 17 00:00:00 2001 From: Rodrigo Brandao Date: Mon, 2 Nov 2026 11:57:57 -0800 Subject: [PATCH 2/2] Removing logging of potentially sensitive value --- .../microsoft_agents/authentication/msal/msal_auth.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/libraries/microsoft-agents-authentication-msal/microsoft_agents/authentication/msal/msal_auth.py b/libraries/microsoft-agents-authentication-msal/microsoft_agents/authentication/msal/msal_auth.py index 86eca6635..4363f4dff 100644 --- a/libraries/microsoft-agents-authentication-msal/microsoft_agents/authentication/msal/msal_auth.py +++ b/libraries/microsoft-agents-authentication-msal/microsoft_agents/authentication/msal/msal_auth.py @@ -62,9 +62,7 @@ def __init__(self, msal_configuration: AgentAuthConfiguration): # TokenCache is thread-safe and async-safe per MSAL documentation self._token_cache = TokenCache() - logger.debug( - "Initializing MsalAuth with configuration: %s", self._msal_configuration - ) + logger.debug("Initializing MsalAuth") @property def configuration(self) -> AgentAuthConfiguration: