Merge pull request #64 from chr1st1ank/adding-tests

Adding a test suite for flask

Author: bobbui

.github/workflows/code_quality.yml

@@ -0,0 +1,55 @@
+
+name: Code Quality
+on:
+  push:
+    branches: [ master ]
+  pull_request:
+    branches: [ master ]
+
+jobs:
+  flake8:
+    name: Flake8
+
+    runs-on: ubuntu-latest
+
+    steps:
+    - uses: actions/checkout@v2
+    - name: Set up Python 3.9
+      uses: actions/setup-python@v2
+      with:
+        python-version: 3.9
+    - name: Install dependencies
+      run: |
+        python -m pip install --upgrade pip
+        pip install -r test-requirements.txt
+    - name: Flake8
+      run: |
+        # stop the build if there are Python syntax errors or undefined names
+        flake8 . --count --select=E9,F63,F7,F82 --show-source --statistics
+        # exit-zero treats all errors as warnings. The GitHub editor is 127 chars wide
+        flake8 . --count --exit-zero --max-complexity=10 --max-line-length=127 --statistics
+
+  tests:
+    name: Tests
+
+    runs-on: ubuntu-latest
+
+    strategy:
+      max-parallel: 4
+      matrix:
+        python-version: ["3.7", "3.8", "3.9"]
+
+    steps:
+      - name: Set up Python ${{ matrix.python-version }}
+        uses: actions/setup-python@v2
+        with:
+          python-version: ${{ matrix.python-version }}
+      - name: "Git checkout"
+        uses: actions/checkout@v2
+      - name: Install dependencies
+        run: |
+          python -m pip install --upgrade pip
+          pip install -r test-requirements.txt
+      - name: Run tests
+        run:  |
+          pytest

test-requirements.txt

@@ -1,5 +1,8 @@
 wheel
-flask==1.0
+flask
 connexion[swagger-ui]
 quart
-sanic
+sanic
+flake8
+pytest
+-e .

tests/conftest.py

@@ -0,0 +1,6 @@
+"""Global fixtures and settings for the pytest test suite"""
+import sys
+import os
+
+# Add test helper modules to search path with out making "tests" a Python package
+sys.path.append(os.path.join(os.path.dirname(__file__), "helpers"))

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/helpers/handler.py

@@ -0,0 +1,20 @@
+import logging
+from typing import List
+
+
+class FormattedMessageCollectorHandler(logging.Handler):
+    """A logging handler that stores formatted log records in its "messages" attribute."""
+
+    def __init__(self, level=logging.NOTSET) -> None:
+        """Create a new log handler."""
+        super().__init__(level=level)
+        self.level = level
+        self.messages: List[str] = []
+
+    def emit(self, record: logging.LogRecord) -> None:
+        """Keep the log records in a list in addition to the log text."""
+        self.messages.append(self.format(record))
+
+    def reset(self) -> None:
+        """Empty the list of messages"""
+        self.messages = []

tests/test_flask.py

@@ -0,0 +1,150 @@
+"""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):
+    """Test if log messages are formatted correctly for all log levels"""
+    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):
+    """Test if a given correlation ID is added to the logs"""
+    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):
+    """Test if a missing correlation ID is replaced by an autogenerated UUID"""
+    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):
+    """Test adding an extra property to a log message"""
+    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):
+    """Test if the details of a stack trace are logged"""
+    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"