diff --git a/.github/actions/waffles/requirements.txt b/.github/actions/waffles/requirements.txt index 52db0f2a..6bed782a 100644 --- a/.github/actions/waffles/requirements.txt +++ b/.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/notifier-utils.git@52.0.14#egg=notifications-utils +git+https://github.com/cds-snc/notifier-utils.git@52.0.15#egg=notifications-utils diff --git a/notifications_utils/logging.py b/notifications_utils/logging.py index 8df9495b..2ccb5bff 100644 --- a/notifications_utils/logging.py +++ b/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)) diff --git a/pyproject.toml b/pyproject.toml index e3940782..e8c382b6 100644 --- a/pyproject.toml +++ b/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" diff --git a/tests/test_logging.py b/tests/test_logging.py index a29f32e8..1944092b 100644 --- a/tests/test_logging.py +++ b/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