From 3ca0d5a7611cd5b1b5c9d2d86c2f2986a2220bab Mon Sep 17 00:00:00 2001
From: Marcos Prieto <marcospri@gmail.com>
Date: Mon, 8 Jul 2024 17:12:21 +0200
Subject: [PATCH] Log validation errors to the console as debug entries.

These are useful to debugging issues in production. We log the same
message displayed to users.
---
 lms/services/jwt.py                                  |  4 ----
 lms/views/exceptions.py                              |  1 +
 .../lti_certification/v13/core/test_bad_payloads.py  | 12 +++++-------
 3 files changed, 6 insertions(+), 11 deletions(-)

diff --git a/lms/services/jwt.py b/lms/services/jwt.py
index 44b36181a3..398bda234e 100644
--- a/lms/services/jwt.py
+++ b/lms/services/jwt.py
@@ -92,11 +92,9 @@ def decode_lti_token(self, id_token: str) -> dict:
                 id_token, options={"verify_signature": False}
             )
         except PyJWTError as err:
-            LOG.debug("Invalid JWT. %s", str(err))
             raise ValidationError(messages={"jwt": [f"Invalid JWT. {err}"]}) from err
 
         if not unverified_header.get("kid"):
-            LOG.debug("Missing 'kid' value in JWT header")
             raise ValidationError(
                 messages={"jwt": ["Missing 'kid' value in JWT header"]}
             )
@@ -105,7 +103,6 @@ def decode_lti_token(self, id_token: str) -> dict:
         # Find the registration based on the token's claimed issuer & audience
         registration = self._registration_service.get(iss, aud)
         if not registration:
-            LOG.debug("Unknown registration for lti_token. iss:%s aud:%s.", iss, aud)
             raise ValidationError(
                 messages={
                     "jwt": [f"Unknown registration for JWT. iss:{iss} aud:{aud}."]
@@ -125,7 +122,6 @@ def decode_lti_token(self, id_token: str) -> dict:
                 leeway=self.LEEWAY,
             )
         except PyJWTError as err:
-            LOG.debug("Invalid JWT for: %s, %s. %s", iss, aud, str(err))
             raise ValidationError(
                 messages={"jwt": [f"Invalid JWT for: {iss}, {aud}. {err}"]}
             ) from err
diff --git a/lms/views/exceptions.py b/lms/views/exceptions.py
index 4f3cf34b58..171dcb8d95 100644
--- a/lms/views/exceptions.py
+++ b/lms/views/exceptions.py
@@ -39,6 +39,7 @@ def forbidden(self):
                 self.exception = exception
                 raise exception
             except ValidationError:
+                LOG.debug("Validation error: %s", exception.messages)
                 self.request.override_renderer = (
                     "lms:templates/validation_error.html.jinja2"
                 )
diff --git a/tests/functional/lti_certification/v13/core/test_bad_payloads.py b/tests/functional/lti_certification/v13/core/test_bad_payloads.py
index 9736187c25..366debaa30 100644
--- a/tests/functional/lti_certification/v13/core/test_bad_payloads.py
+++ b/tests/functional/lti_certification/v13/core/test_bad_payloads.py
@@ -21,7 +21,7 @@ def test_no_kid_sent_in_jwt_header(
 
         do_lti_launch({"id_token": make_jwt(test_payload, jwt_headers)}, status=403)
 
-        assert "Missing 'kid' value in JWT header" in caplog.messages
+        assert "Missing 'kid' value in JWT header" in "".join(caplog.messages)
 
     def test_incorrect_kid_in_jwt_header(
         self, jwt_headers, test_payload, do_lti_launch, make_jwt, caplog
@@ -29,12 +29,10 @@ def test_incorrect_kid_in_jwt_header(
         jwt_headers["kid"] = "imstester_66067"
 
         do_lti_launch({"id_token": make_jwt(test_payload, jwt_headers)}, status=403)
-        assert (
-            Any.string.matching(
-                "^Invalid JWT for:.* Unable to find a signing key that matches:.*$"
-            )
-            in caplog.messages
-        )
+
+        assert Any.string.matching(
+            ".*Invalid JWT for:.* Unable to find a signing key that matches:.*$"
+        ) == "".join(caplog.messages)
 
     def test_wrong_lti_version(self, make_jwt, test_payload, do_lti_launch):
         """The LTI version claim contains the wrong version"""