Replace a signed secret in the api log message (#261)

* Replace a signed secret in the api log message

* add new version for deployment

.github/actions/waffles/requirements.txt

@@ -1,4 +1,4 @@
 docopt==0.6.2
 Flask==2.3.3
 markupsafe==2.1.3
-git+https://github.com/cds-snc/[email protected].14#egg=notifications-utils
+git+https://github.com/cds-snc/[email protected].15#egg=notifications-utils

notifications_utils/logging.py

@@ -15,6 +15,8 @@
 LOG_FORMAT = "%(asctime)s %(app_name)s %(name)s %(levelname)s " '%(request_id)s "%(message)s" [in %(pathname)s:%(lineno)d]'
 TIME_FORMAT = "%Y-%m-%dT%H:%M:%S"
 
+regex_pattern_for_replace_api_signed_secret = "[a-zA-Z0-9]{51}\.[a-zA-Z0-9-_]{27}"  # noqa: W605
+
 logger = logging.getLogger(__name__)
 
 
@@ -200,6 +202,8 @@ def add_fields(self, record):
     def format(self, record):
         record = self.add_fields(record)
         try:
+            # Replace the API signed secret with asterisks
+            record.msg = re.sub(regex_pattern_for_replace_api_signed_secret, "***", record.msg)
             # sometimes record.msg is an exception so this is checking for that
             if isinstance(record.msg, str):
                 record.msg += _getAdditionalLoggingDetails()
@@ -221,6 +225,8 @@ def process_log_record(self, log_record):
             log_record[newkey] = log_record.pop(key)
         log_record["logType"] = "application"
         try:
+            # Replace the API signed secret with asterisks
+            log_record["message"] = re.sub(regex_pattern_for_replace_api_signed_secret, "***", log_record["message"])
             log_record["message"] = str(log_record["message"])
         except (KeyError, IndexError) as e:
             logger.exception("failed to format log message: {} not found".format(e))

pyproject.toml

@@ -5,7 +5,7 @@ include = '(notifications_utils|tests)/.*\.pyi?$'
 
 [tool.poetry]
 name = "notifications-utils"
-version = "52.0.14"
+version = "52.0.15"
 description = "Shared python code for Notification - Provides logging utils etc."
 authors = ["Canadian Digital Service"]
 license = "MIT license"

tests/test_logging.py

@@ -243,3 +243,67 @@ def critical():
             assert "template_id" in errorMessage
             # ensure request data (endpoint) is shown
             assert "endpoint" in errorMessage
+
+
+@pytest.mark.parametrize("debugconfig", [True, False])
+@pytest.mark.parametrize("testcases", [("info", "warning", "error", "exception", "critical")])
+def test_logger_adds_extra_context_details_final(app, mocker, debugconfig, testcases):  # noqa
+    def createApp(app):
+        app.debug = debugconfig
+
+        api_signed_secret = "IjRlNzMxN2I0LWQwYTMtNDUzNS04NWViLTRhZWVmMjgxNTc2ZSI.KTFF78gIrz8ftQG6eMm1hjKXkz0"
+
+        @app.route("/info", methods=["POST"])
+        def info():
+            app.logger.info(f"info {api_signed_secret}")
+            return "ok"
+
+        @app.route("/warning", methods=["POST"])
+        def warning():
+            app.logger.warning(f"warning {api_signed_secret}")
+            return "ok"
+
+        @app.route("/error", methods=["POST"])
+        def error():
+            app.logger.error(f"error {api_signed_secret}")
+            return "ok"
+
+        @app.route("/exception", methods=["POST"])
+        def exception():
+            app.logger.exception(f"exception {api_signed_secret}")
+            return "ok"
+
+        @app.route("/critical", methods=["POST"])
+        def critical():
+            app.logger.critical(f"critical {api_signed_secret}")
+            return "ok"
+
+        logging.init_app(app)
+
+    createApp(app)
+
+    if debugconfig:
+        log_spy = mocker.spy(logging.CustomLogFormatter, "format")
+    else:
+        log_spy = mocker.spy(logging.JSONFormatter, "process_log_record")
+
+    with app.app_context():
+        for route in testcases:
+            app.test_client().post(
+                f"/{route}", data=json.dumps({"template_id": "1234"}), headers={"Content-Type": "application/json"}
+            )
+
+            if debugconfig:
+                errorMessage = log_spy.spy_return  # message is returned as a string when using the CustomLogFormatter
+            else:
+                errorMessage = log_spy.spy_return["message"]  # message is embedded in JSON when using the JSONFormatter
+
+            # ensure extra request details are being added
+            assert "Request details" in errorMessage
+            # ensure body data (template_id) is shown
+            assert "template_id" in errorMessage
+            # ensure request data (endpoint) is shown
+            assert "endpoint" in errorMessage
+            # ensure Secret_key not in errorMessage
+            assert "IjRlNzMxN2I0LWQwYTMtNDUzNS04NWViLTRhZWVmMjgxNTc2ZSI.KTFF78gIrz8ftQG6eMm1hjKXkz0" not in errorMessage
+            assert "***" in errorMessage