Test suite for flask

Author: chr1st1ank

tests/helpers/constants.py

@@ -0,0 +1,14 @@
+"""Constants shared by multiple tests"""
+
+STANDARD_MSG_ATTRIBUTES = {
+    "written_at",
+    "written_ts",
+    "msg",
+    "type",
+    "logger",
+    "thread",
+    "level",
+    "module",
+    "line_no",
+    "correlation_id",
+}

tests/test_flask.py

@@ -0,0 +1,145 @@
+"""Test suite for the flask backend"""
+import json
+import logging
+import pathlib
+import re
+import sys
+
+import flask
+import pytest
+
+from helpers import constants
+from helpers.handler import FormattedMessageCollectorHandler
+
+LOGGER_NAME = "flask-test"
+
+
+@pytest.fixture
+def client_and_log_handler():
+    import json_logging
+
+    # Init app
+    app = flask.Flask(__name__)
+
+    # Init std logging
+    logger = logging.getLogger(LOGGER_NAME)
+    logger.setLevel(logging.DEBUG)
+    handler = FormattedMessageCollectorHandler()
+    logger.addHandler(handler)
+
+    # Add json_logging
+    json_logging.init_flask(enable_json=True)
+    json_logging.init_request_instrument(app)
+
+    # Prepare test endpoints
+    @app.route("/log/levels/debug")
+    def log_debug():
+        logger.debug("debug message")
+        return {}
+
+    @app.route("/log/levels/info")
+    def log_info():
+        logger.info("info message")
+        return {}
+
+    @app.route("/log/levels/error")
+    def log_error():
+        logger.error("error message")
+        return {}
+
+    @app.route("/log/extra_property")
+    def extra_property():
+        logger.info(
+            "test log statement with extra props",
+            extra={"props": {"extra_property": "extra_value"}},
+        )
+        return {}
+
+    @app.route("/log/exception")
+    def log_exception():
+        try:
+            raise RuntimeError()
+        except BaseException as e:
+            logger.exception("Error occurred", exc_info=e)
+        return {}
+
+    with app.test_client() as test_client:
+        yield test_client, handler
+
+    # Tear down test environment
+    logger.removeHandler(handler)
+    del sys.modules["json_logging"]  # "de-import" because json_logging maintains global state
+
+
+@pytest.mark.parametrize("level", ["debug", "info", "error"])
+def test_record_format_per_log_level(client_and_log_handler, level):
+    api_client, handler = client_and_log_handler
+
+    response = api_client.get("/log/levels/" + level)
+
+    assert response.status_code == 200
+    assert len(handler.messages) == 1
+    msg = json.loads(handler.messages[0])
+    assert set(msg.keys()) == constants.STANDARD_MSG_ATTRIBUTES
+    assert msg["module"] == __name__
+    assert msg["level"] == level.upper()
+    assert msg["logger"] == LOGGER_NAME
+    assert msg["type"] == "log"
+    assert msg["msg"] == level + " message"
+    assert re.match(
+        r"^\d{4}-\d\d-\d\dT\d\d:\d\d:\d\d(\.\d+.*)?$", msg["written_at"]
+    ), "The field 'written_at' does not contain an iso timestamp"
+
+
+def test_correlation_id_given(client_and_log_handler):
+    api_client, handler = client_and_log_handler
+
+    response = api_client.get("/log/levels/debug", headers={"X-Correlation-Id": "abc-def"})
+
+    assert response.status_code == 200
+    assert len(handler.messages) == 1
+    msg = json.loads(handler.messages[0])
+    assert set(msg.keys()) == constants.STANDARD_MSG_ATTRIBUTES
+    assert msg["correlation_id"] == "abc-def"
+
+
+def test_correlation_id_generated(client_and_log_handler):
+    api_client, handler = client_and_log_handler
+
+    response = api_client.get("/log/levels/debug")
+
+    assert response.status_code == 200
+    assert len(handler.messages) == 1
+    msg = json.loads(handler.messages[0])
+    assert set(msg.keys()) == constants.STANDARD_MSG_ATTRIBUTES
+    assert re.match(
+        r"^[0-9a-f]{8}-[0-9a-f]{4}-[0-5][0-9a-f]{3}-[089ab][0-9a-f]{3}-[0-9a-f]{12}$",
+        msg["correlation_id"],
+    ), "autogenerated UUID doesn't have expected format"
+
+
+def test_extra_property(client_and_log_handler):
+    api_client, handler = client_and_log_handler
+
+    response = api_client.get("/log/extra_property")
+
+    assert response.status_code == 200
+    assert len(handler.messages) == 1
+    msg = json.loads(handler.messages[0])
+    assert set(msg.keys()) == constants.STANDARD_MSG_ATTRIBUTES.union({"extra_property"})
+    assert msg["extra_property"] == "extra_value"
+
+
+def test_exception_logged_with_stack_trace(client_and_log_handler):
+    api_client, handler = client_and_log_handler
+
+    response = api_client.get("/log/exception")
+
+    assert response.status_code == 200
+    assert len(handler.messages) == 1
+    msg = json.loads(handler.messages[0])
+    assert set(msg.keys()) == constants.STANDARD_MSG_ATTRIBUTES.union({"exc_info", "filename"})
+    assert msg["filename"] == pathlib.Path(__file__).name, "File name for exception not logged"
+    assert "Traceback (most recent call last):" in msg["exc_info"], "Not a stack trace"
+    assert "RuntimeError" in msg["exc_info"], "Exception type not logged"
+    assert len(msg["exc_info"].split("\n")) > 2, "Stacktrace doesn't have multiple lines"