Merge pull request #176 from Aiven-Open/kmichel-adjust-get-call-log-l…

…evel

lower log level of GET calls to DEBUG

astacus/common/access_log.py

@@ -0,0 +1,16 @@
+"""
+Copyright (c) 2024 Aiven Ltd
+See LICENSE for details
+"""
+from collections.abc import Sequence
+
+import logging
+
+
+class AccessLogLevelFilter(logging.Filter):
+    def filter(self, record: logging.LogRecord) -> bool:
+        # Lower the log level of GET requests from INFO to DEBUG
+        if isinstance(record.args, Sequence) and len(record.args) >= 2 and record.args[1] == "GET":
+            record.levelno = logging.DEBUG
+            record.levelname = logging.getLevelName(record.levelno)
+        return True

astacus/server.py

@@ -110,6 +110,11 @@ def _run_server(args) -> bool:
                     "fmt": '%(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s',
                 },
             },
+            "filters": {
+                "access_log_level": {
+                    "()": "astacus.common.access_log.AccessLogLevelFilter",
+                },
+            },
             "handlers": {
                 "default": {
                     "class": "logging.StreamHandler",
@@ -119,6 +124,7 @@ def _run_server(args) -> bool:
                 "access": {
                     "class": "logging.StreamHandler",
                     "formatter": "access",
+                    "filters": ["access_log_level"],
                     "stream": "ext://sys.stdout",
                 },
             },

tests/unit/common/test_access_log.py

@@ -0,0 +1,63 @@
+"""
+Copyright (c) 2024 Aiven Ltd
+See LICENSE for details
+"""
+from astacus.common.access_log import AccessLogLevelFilter
+from collections.abc import Mapping
+from typing import Any
+
+import logging
+import pytest
+
+
+def create_record(msg: str, args: tuple[Any, ...] | Mapping[str, Any]) -> logging.LogRecord:
+    return logging.LogRecord(
+        name="test",
+        level=logging.INFO,
+        pathname="/",
+        lineno=0,
+        msg=msg,
+        args=args,
+        exc_info=None,
+    )
+
+
+def create_access_record(method: str) -> logging.LogRecord:
+    return create_record(
+        msg='%s - "%s %s HTTP/%s" %d',
+        args=("127.0.0.1:1234", method, "/foo", "HTTP/1.1"),
+    )
+
+
+def test_filter_lowers_level_of_get_method() -> None:
+    record = create_access_record(method="GET")
+    should_keep = AccessLogLevelFilter().filter(record)
+    assert should_keep
+    assert record.levelno == logging.DEBUG
+    assert record.levelname == "DEBUG"
+
+
+@pytest.mark.parametrize("method", ["POST", "PUT", "DELETE", "UNKNOWN"])
+def test_filter_keeps_level_of_other_methods(method: str) -> None:
+    record = create_access_record(method=method)
+    should_keep = AccessLogLevelFilter().filter(record)
+    assert should_keep
+    assert record.levelno == logging.INFO
+    assert record.levelname == "INFO"
+
+
+@pytest.mark.parametrize(
+    "record",
+    [
+        create_record(msg="no args", args=()),
+        create_record(msg="one arg:%s", args=("arg",)),
+        create_record(msg="arg1:%s, arg2: %s", args=("arg1", 2)),
+        create_record(msg="dict arg: %(a)s", args=({"a": 1},)),
+    ],
+    ids=["no args", "one arg", "non-method arg2", "dict args"],
+)
+def test_filter_ignores_surprising_log_messages(record: logging.LogRecord) -> None:
+    should_keep = AccessLogLevelFilter().filter(record)
+    assert should_keep
+    assert record.levelno == logging.INFO
+    assert record.levelname == "INFO"