Fix token cache debug log redaction

msal/token_cache.py

@@ -381,10 +381,11 @@ def make_clean_copy(dictionary, sensitive_fields):  # Masks sensitive info
                 for k, v in dictionary.items()
             }
         clean_event = dict(
-            event,
+            make_clean_copy(event, ("username", "_account_id")),
             data=make_clean_copy(event.get("data", {}), (
                 "password", "client_secret", "refresh_token", "assertion",
-                "user_federated_identity_credential",
+                "client_assertion", "user_federated_identity_credential",
+                "code", "code_verifier", "device_code", "username", "user_id",
                 # Client-originated claims may carry sensitive values; they are
                 # kept in data only for ext_cache_key computation, so redact them
                 # from the debug log (both the cache-key pseudo-param and the
@@ -394,6 +395,7 @@ def make_clean_copy(dictionary, sensitive_fields):  # Masks sensitive info
             response=make_clean_copy(event.get("response", {}), (
                 "id_token_claims",  # Provided by broker
                 "access_token", "refresh_token", "id_token", "username",
+                "client_info", "_account_id",
             )),
         )
         logger.debug("event=%s", json.dumps(

tests/test_token_cache.py

@@ -1,5 +1,6 @@
 import logging
 import base64
+import copy
 import json
 import time
 import warnings
@@ -80,6 +81,118 @@ def test_add_redacts_client_claims_in_debug_log(self):
         self.assertNotIn("SENSITIVE", logged)
         self.assertIn("********", logged)
 
+    def test_add_redacts_authentication_data_in_debug_log(self):
+        sensitive_data = {
+            "code": "SENSITIVE_AUTHORIZATION_CODE",
+            "code_verifier": "SENSITIVE_PKCE_VERIFIER",
+            "device_code": "SENSITIVE_DEVICE_CODE",
+            "username": "SENSITIVE_REQUEST_USERNAME",
+            "user_id": "SENSITIVE_USER_ID",
+            "password": "SENSITIVE_PASSWORD",
+            "client_secret": "SENSITIVE_CLIENT_SECRET",
+            "client_assertion": "SENSITIVE_CLIENT_ASSERTION",
+            "refresh_token": "SENSITIVE_REQUEST_REFRESH_TOKEN",
+            "assertion": b"SENSITIVE_ASSERTION",
+            "user_federated_identity_credential": "SENSITIVE_FEDERATED_CREDENTIAL",
+            "client_claims": '{"custom_claim": "SENSITIVE_CLIENT_CLAIM"}',
+            "claims": '{"access_token": {"custom_claim": "SENSITIVE_CLAIM"}}',
+        }
+        event = {
+            "client_id": "my_client_id",
+            "scope": ["s1"],
+            "grant_type": "authorization_code",
+            "token_endpoint": "https://login.example.com/contoso/v2/token",
+            "username": "SENSITIVE_EVENT_USERNAME",
+            "data": dict(sensitive_data, redirect_uri="http://localhost"),
+            "response": build_response(
+                uid="SENSITIVE_UID", utid="SENSITIVE_UTID",
+                access_token="SENSITIVE_ACCESS_TOKEN",
+                refresh_token="SENSITIVE_RESPONSE_REFRESH_TOKEN",
+                id_token=build_id_token(sub="SENSITIVE_SUBJECT"),
+                id_token_claims={"sub": "SENSITIVE_SUBJECT"},
+                username="SENSITIVE_RESPONSE_USERNAME"),
+        }
+        original_event = copy.deepcopy(event)
+        expected_log = copy.deepcopy(event)
+        expected_log["username"] = "********"
+        expected_log["data"].update({k: "********" for k in sensitive_data})
+        expected_log["response"].update({k: "********" for k in (
+            "access_token", "refresh_token", "id_token", "id_token_claims",
+            "username", "client_info",
+        )})
+
+        with self.assertLogs("msal.token_cache", level="DEBUG") as cm:
+            self.cache.add(event, now=1000)
+
+        self.assertEqual(event, original_event)
+        for credential_type, field in (
+                (TokenCache.CredentialType.ACCESS_TOKEN, "access_token"),
+                (TokenCache.CredentialType.REFRESH_TOKEN, "refresh_token"),
+                (TokenCache.CredentialType.ID_TOKEN, "id_token")):
+            entries = list(self.cache._cache[credential_type].values())
+            self.assertEqual(len(entries), 1)
+            self.assertEqual(entries[0]["secret"], event["response"][field])
+            self.assertEqual(
+                entries[0]["home_account_id"], "SENSITIVE_UID.SENSITIVE_UTID")
+        access_token = next(iter(
+            self.cache._cache[TokenCache.CredentialType.ACCESS_TOKEN].values()))
+        self.assertEqual(
+            access_token["ext_cache_key"],
+            _compute_ext_cache_key(original_event["data"]))
+        self.assertEqual(len(cm.records), 1)
+        self.assertEqual(
+            json.loads(cm.records[0].getMessage().removeprefix("event=")),
+            expected_log)
+        self.assertNotIn("SENSITIVE", "\n".join(cm.output))
+
+    def test_add_redacts_username_without_changing_account(self):
+        for username_location in ("data", "event"):
+            with self.subTest(username_location=username_location):
+                event = {
+                    "client_id": "my_client_id",
+                    "token_endpoint": "https://login.example.com/contoso/v2/token",
+                    "data": {},
+                    "response": build_response(uid="uid", utid="utid"),
+                }
+                source = event["data"] if username_location == "data" else event
+                source["username"] = "SENSITIVE_USERNAME"
+                original_event = copy.deepcopy(event)
+                with self.assertLogs("msal.token_cache", level="DEBUG") as cm:
+                    self.cache.add(event, now=1000)
+                self.assertEqual(event, original_event)
+                account = self.cache._cache["Account"][
+                    "uid.utid-login.example.com-contoso"]
+                self.assertEqual(account["username"], "SENSITIVE_USERNAME")
+                self.assertNotIn("SENSITIVE_USERNAME", "\n".join(cm.output))
+
+    def test_add_redacts_broker_account_id_without_changing_account(self):
+        event = {
+            "client_id": "my_client_id",
+            "grant_type": "broker",
+            "token_endpoint": "https://login.example.com/contoso/v2/token",
+            "_account_id": "SENSITIVE_BROKER_ACCOUNT_ID",
+            "response": build_response(
+                uid="uid", utid="utid", access_token="at",
+                id_token_claims={"sub": "subject"},
+                _account_id="SENSITIVE_BROKER_ACCOUNT_ID"),
+        }
+        original_event = copy.deepcopy(event)
+        with self.assertLogs("msal.token_cache", level="DEBUG") as cm:
+            self.cache.add(event, now=1000)
+
+        self.assertEqual(event, original_event)
+        account = self.cache._cache["Account"][
+            "uid.utid-login.example.com-contoso"]
+        self.assertEqual(
+            account["local_account_id"], "SENSITIVE_BROKER_ACCOUNT_ID")
+        self.assertEqual(account["account_source"], "broker")
+        self.assertEqual(len(cm.records), 1)
+        logged_event = json.loads(
+            cm.records[0].getMessage().removeprefix("event="))
+        self.assertEqual(logged_event["_account_id"], "********")
+        self.assertEqual(logged_event["response"]["_account_id"], "********")
+        self.assertNotIn("SENSITIVE_BROKER_ACCOUNT_ID", "\n".join(cm.output))
+
     def testAddByAad(self):
         client_id = "my_client_id"
         id_token = build_id_token(