Move log initialization to app.py

asgi.py

@@ -1,22 +1,17 @@
 import uvicorn
 
 from ctms.config import Settings
-from ctms.log import configure_logging
 
 settings = Settings()
 
 
 if __name__ == "__main__":
-    logging_config = configure_logging(
-        settings.use_mozlog, settings.logging_level.name, settings.log_sqlalchemy
-    )
-
     server = uvicorn.Server(
         uvicorn.Config(
             "ctms.app:app",
             host=settings.host,
             port=settings.port,
-            log_config=logging_config,
+            log_config=None,
         )
     )
     server.run()

ctms/app.py

@@ -12,7 +12,7 @@
 from .config import get_version
 from .database import SessionLocal
 from .exception_capture import init_sentry
-from .log import context_from_request, get_log_line
+from .log import CONFIG as LOG_CONFIG, context_from_request, get_log_line
 from .metrics import (
     METRICS_REGISTRY,
     emit_response_metrics,
@@ -24,6 +24,8 @@
 from .routers import contacts, platform
 
 
+logging.config.dictConfig(LOG_CONFIG)
+
 web_logger = logging.getLogger("ctms.web")
 
 app = FastAPI(

ctms/log.py

@@ -3,68 +3,60 @@
 import logging
 import logging.config
 import sys
-from typing import Any, Dict, List, Optional
+from typing import Any, Dict, Optional
 
 from dockerflow.logging import request_id_context
 from fastapi import Request
 from starlette.routing import Match
 
+from ctms.config import Settings
 
-def configure_logging(
-    use_mozlog: bool = True, logging_level: str = "INFO", log_sqlalchemy: bool = False
-) -> dict:
-    """Configure Python logging.
+settings = Settings()
 
-    :param use_mozlog: If True, use MozLog format, appropriate for deployments.
-        If False, format logs for human consumption.
-    :param logging_level: The logging level, such as DEBUG or INFO.
-    :param log_sqlalchemy: Include SQLAlchemy engine logs, such as SQL statements
-    """
-    logging_config = {
-        "version": 1,
-        "disable_existing_loggers": False,
-        "filters": {
-            "request_id": {
-                "()": "dockerflow.logging.RequestIdLogFilter",
-            },
+CONFIG = {
+    "version": 1,
+    "disable_existing_loggers": False,
+    "filters": {
+        "request_id": {
+            "()": "dockerflow.logging.RequestIdLogFilter",
         },
-        "formatters": {
-            "mozlog_json": {
-                "()": "dockerflow.logging.JsonLogFormatter",
-                "logger_name": "ctms",
-            },
-            "text": {
-                "format": "%(asctime)s %(levelname)-8s [%(rid)s] %(name)-15s %(message)s",
-                "datefmt": "%Y-%m-%d %H:%M:%S",
-            },
+    },
+    "formatters": {
+        "mozlog_json": {
+            "()": "dockerflow.logging.JsonLogFormatter",
+            "logger_name": "ctms",
         },
-        "handlers": {
-            "console": {
-                "level": logging_level,
-                "class": "logging.StreamHandler",
-                "filters": ["request_id"],
-                "formatter": "mozlog_json" if use_mozlog else "text",
-                "stream": sys.stdout,
-            },
-            "null": {
-                "class": "logging.NullHandler",
-            },
+        "text": {
+            "format": "%(asctime)s %(levelname)-8s [%(rid)s] %(name)-15s %(message)s",
+            "datefmt": "%Y-%m-%d %H:%M:%S",
         },
-        "loggers": {
-            "": {"handlers": ["console"], "level": logging_level},
-            "alembic": {"level": logging_level},
-            "ctms": {"level": logging_level},
-            "uvicorn": {"level": logging_level},
-            "uvicorn.access": {"handlers": ["null"], "propagate": False},
-            "sqlalchemy.engine": {
-                "level": logging_level if log_sqlalchemy else logging.WARNING,
-                "propagate": False,
-            },
+    },
+    "handlers": {
+        "console": {
+            "level": settings.logging_level.name,
+            "class": "logging.StreamHandler",
+            "filters": ["request_id"],
+            "formatter": "mozlog_json" if settings.use_mozlog else "text",
+            "stream": sys.stdout,
         },
-    }
-    logging.config.dictConfig(logging_config)
-
-    return logging_config
+        "null": {
+            "class": "logging.NullHandler",
+        },
+    },
+    "loggers": {
+        "": {"handlers": ["console"]},
+        "request.summary": {"level": logging.INFO},
+        "ctms": {"handlers": ["console"], "level": logging.NOTSET},
+        "uvicorn": {"level": logging.INFO},
+        "uvicorn.access": {"handlers": ["null"], "propagate": False},
+        "sqlalchemy.engine": {
+            "level": settings.logging_level.name
+            if settings.log_sqlalchemy
+            else logging.WARNING,
+            "propagate": False,
+        },
+    },
+}
 
 
 def context_from_request(request: Request) -> Dict:

tests/unit/test_log.py

@@ -7,8 +7,6 @@
 import pytest
 from requests.auth import HTTPBasicAuth
 
-from ctms.log import configure_logging
-
 
 def test_request_log(client, email_factory, caplog):
     """A request is logged."""
@@ -100,21 +98,3 @@ def test_log_crash(client, caplog):
     assert log["log_level"] == "error"
     assert "rid" in log
     assert log["event"] == "testclient:50000 test_client 'GET /__crash__ HTTP/1.1' 500"
-
-
-@pytest.mark.parametrize(
-    "use_mozlog,logging_level",
-    (
-        (True, "INFO"),
-        (False, "WARNING"),
-    ),
-)
-def test_configure_logging(use_mozlog, logging_level):
-    with patch("ctms.log.logging.config.dictConfig") as mock_dc:
-        configure_logging(use_mozlog, logging_level)
-    mock_dc.assert_called_once()
-    (args,) = mock_dc.mock_calls[0].args
-    assert (
-        args["handlers"]["console"]["formatter"] == "mozlog" if use_mozlog else "text"
-    )
-    assert args["loggers"]["ctms"]["level"] == logging_level