fix: redact bot_access_tokens from the debug logs of socket mode (#1519)

Author: WilliamBergamin

slack_sdk/socket_mode/builtin/client.py

@@ -20,6 +20,7 @@
 from slack_sdk.web import WebClient
 from .connection import Connection, ConnectionState
 from ..interval_runner import IntervalRunner
+from ..logger.messages import debug_redacted_message_string
 from ...errors import SlackClientConfigurationError, SlackClientNotConnectedError
 from ...proxy_env_variable_loader import load_http_proxy_from_env
 
@@ -231,7 +232,7 @@ def close(self):
 
     def _on_message(self, message: str):
         if self.logger.level <= logging.DEBUG:
-            self.logger.debug(f"on_message invoked: (message: {message})")
+            self.logger.debug(f"on_message invoked: (message: {debug_redacted_message_string(message)})")
         self.enqueue_message(message)
         for listener in self.on_message_listeners:
             listener(message)

slack_sdk/socket_mode/logger/__init__.py

@@ -0,0 +1,6 @@
+import re
+
+
+def debug_redacted_message_string(message: str) -> str:
+    xwfp_token_pattern = re.compile(r"\"xwfp-[A-Za-z0-9\-]+\"")  # ex: "xwfp-abc-ABC-1234"
+    return re.sub(xwfp_token_pattern, "[[REDACTED]]", message)

slack_sdk/socket_mode/logger/messages.py

@@ -24,6 +24,8 @@
 from slack_sdk.socket_mode.request import SocketModeRequest
 from slack_sdk.web import WebClient
 
+from ..logger.messages import debug_redacted_message_string
+
 
 class SocketModeClient(BaseSocketModeClient):
     logger: Logger
@@ -147,7 +149,7 @@ def on_open(ws: WebSocketApp):
 
         def on_message(ws: WebSocketApp, message: str):
             if self.logger.level <= logging.DEBUG:
-                self.logger.debug(f"on_message invoked: (message: {message})")
+                self.logger.debug(f"on_message invoked: (message: {debug_redacted_message_string(message)})")
             self.enqueue_message(message)
             for listener in self.on_message_listeners:
                 listener(ws, message)

slack_sdk/socket_mode/websocket_client/__init__.py

@@ -26,6 +26,8 @@
 from slack_sdk.socket_mode.request import SocketModeRequest
 from slack_sdk.web.async_client import AsyncWebClient
 
+from ..logger.messages import debug_redacted_message_string
+
 
 class SocketModeClient(AsyncBaseSocketModeClient):
     logger: Logger
@@ -149,7 +151,9 @@ async def receive_messages(self) -> None:
                         if isinstance(message, bytes):
                             message = message.decode("utf-8")
                         if self.logger.level <= logging.DEBUG:
-                            self.logger.debug(f"Received message: {message}, session: {session_id}")
+                            self.logger.debug(
+                                f"Received message: {debug_redacted_message_string(message)}, session: {session_id}"
+                            )
                         await self.enqueue_message(message)
                     consecutive_error_count = 0
                 except Exception as e:

slack_sdk/socket_mode/websockets/__init__.py

@@ -0,0 +1,26 @@
+import unittest
+
+from slack_sdk.socket_mode.logger.messages import debug_redacted_message_string
+
+
+class TestRequest(unittest.TestCase):
+    def setUp(self):
+        pass
+
+    def tearDown(self):
+        pass
+
+    def test_debug_redacted_message_string(self):
+        message = """{"envelope_id":"abc-123","payload":{"token":"xxx","team_id":"T123","api_app_id":"A123","event":{"type":"function_executed","function":{"id":"Fn123","callback_id":"sample_function","title":"Sample function","description":"","type":"app","input_parameters":[],"output_parameters":[],"app_id":"A123","date_created":1719416102,"date_released":0,"date_updated":1719426759,"date_deleted":0,"form_enabled":false},"inputs":{"user_id":"U123"},"function_execution_id":"Fx123","workflow_execution_id":"Wx079QN9CT8E","event_ts":"1719427571.129426","bot_access_token":"xwfp-123-abc"},"type":"event_callback","event_id":"Ev123","event_time":1719427571},"type":"events_api","accepts_response_payload":false,"retry_attempt":0,"retry_reason":""}"""
+        redacted_message = debug_redacted_message_string(message)
+        self.assertEqual(redacted_message.count('"bot_access_token":[[REDACTED]]'), 1)
+
+    def test_debug_redacted_message_string_no_changes(self):
+        message = """{"envelope_id":"abc-123","payload":{"token":"xxx","team_id":"T123","api_app_id":"A123","event":{"type":"function_executed","function":{"id":"Fn123","callback_id":"sample_function","title":"Sample function","description":"","type":"app","input_parameters":[],"output_parameters":[],"app_id":"A123","date_created":1719416102,"date_released":0,"date_updated":1719426759,"date_deleted":0,"form_enabled":false},"inputs":{"user_id":"U123"},"function_execution_id":"Fx123","workflow_execution_id":"Wx079QN9CT8E","event_ts":"1719427571.129426"},"type":"event_callback","event_id":"Ev123","event_time":1719427571},"type":"events_api","accepts_response_payload":false,"retry_attempt":0,"retry_reason":""}"""
+        redacted_message = debug_redacted_message_string(message)
+        self.assertEqual(redacted_message.count('"bot_access_token":[[REDACTED]]'), 0)
+
+    def test_debug_redacted_message_string_simple(self):
+        message = '"bot_access_token": "xwfp-123-abc"'
+        redacted_message = debug_redacted_message_string(message)
+        self.assertEqual(redacted_message.count('"bot_access_token": [[REDACTED]]'), 1)