fix(fastapi): centralize logging initialization

With this change, we provide a wrapper to `logging.getLogger`
in the `aurweb.logging` module. Modules wishing to log using
logging.conf should get their module-local loggers by calling
`aurweb.logging.getLogger(__name__)`, similar to `logging.getLogger`,
this way initialization with logging.conf is guaranteed.

Signed-off-by: Kevin Morris <kevr@0cost.org>

aurweb/logging.py

@@ -8,4 +8,14 @@ aurwebdir = aurweb.config.get("options", "aurwebdir")
 config_path = os.path.join(aurwebdir, "logging.conf")
 
 logging.config.fileConfig(config_path, disable_existing_loggers=False)
-logger = logging.getLogger(__name__)
+
+
+def get_logger(name: str) -> logging.Logger:
+    """ A logging.getLogger wrapper. Importing this function and
+    using it to get a module-local logger ensures that logging.conf
+    initialization is performed wherever loggers are used.
+
+    :param name: Logger name; typically `__name__`
+    :returns: name's logging.Logger
+    """
+    return logging.getLogger(name)

aurweb/redis.py

@@ -1,12 +1,12 @@
-import logging
-
 import fakeredis
 
 from redis import ConnectionPool, Redis
 
 import aurweb.config
 
-logger = logging.getLogger(__name__)
+from aurweb import logging
+
+logger = logging.get_logger(__name__)
 pool = None
 
 

aurweb/routers/accounts.py

@@ -1,5 +1,4 @@
 import copy
-import logging
 import typing
 
 from datetime import datetime
@@ -11,7 +10,7 @@ from sqlalchemy import and_, func, or_
 
 import aurweb.config
 
-from aurweb import db, l10n, models, time, util
+from aurweb import db, l10n, logging, models, time, util
 from aurweb.auth import account_type_required, auth_required
 from aurweb.captcha import get_captcha_answer, get_captcha_salts, get_captcha_token
 from aurweb.l10n import get_translator_for_request
@@ -21,7 +20,7 @@ from aurweb.scripts.notify import ResetKeyNotification, WelcomeNotification
 from aurweb.templates import make_context, make_variable_context, render_template
 
 router = APIRouter()
-logger = logging.getLogger(__name__)
+logger = logging.get_logger(__name__)
 
 
 @router.get("/passreset", response_class=HTMLResponse)

aurweb/routers/trusted_user.py

@@ -1,5 +1,4 @@
 import html
-import logging
 import re
 import typing
 
@@ -10,13 +9,13 @@ from fastapi import APIRouter, Form, HTTPException, Request
 from fastapi.responses import RedirectResponse, Response
 from sqlalchemy import and_, or_
 
-from aurweb import db, l10n, models
+from aurweb import db, l10n, logging, models
 from aurweb.auth import account_type_required, auth_required
 from aurweb.models.account_type import DEVELOPER, TRUSTED_USER, TRUSTED_USER_AND_DEV
 from aurweb.templates import make_context, make_variable_context, render_template
 
 router = APIRouter()
-logger = logging.getLogger(__name__)
+logger = logging.get_logger(__name__)
 
 # Some TU route specific constants.
 ITEMS_PER_PAGE = 10  # Paged table size.

aurweb/scripts/rendercomment.py

@@ -1,6 +1,5 @@
 #!/usr/bin/env python3
 
-import logging
 import sys
 
 import bleach
@@ -10,7 +9,9 @@ import pygit2
 import aurweb.config
 import aurweb.db
 
-logger = logging.getLogger(__name__)
+from aurweb import logging
+
+logger = logging.get_logger(__name__)
 repo_path = aurweb.config.get('serve', 'repo-path')
 commit_uri = aurweb.config.get('options', 'commit_uri')
 

aurweb/util.py

@@ -1,6 +1,5 @@
 import base64
 import copy
-import logging
 import math
 import random
 import re
@@ -20,7 +19,9 @@ from jinja2 import pass_context
 
 import aurweb.config
 
-logger = logging.getLogger(__name__)
+from aurweb import logging
+
+logger = logging.get_logger(__name__)
 
 
 def make_random_string(length):

logging.conf

@@ -15,13 +15,13 @@ handlers=simpleHandler
 level=DEBUG
 handlers=detailedHandler
 qualname=aurweb
-propagate=0
+propagate=1
 
 [logger_test]
 level=DEBUG
 handlers=detailedHandler
 qualname=test
-propagate=0
+propagate=1
 
 [logger_uvicorn]
 level=DEBUG

test/test_accounts_routes.py

@@ -1,4 +1,3 @@
-import logging
 import re
 import tempfile
 
@@ -11,7 +10,7 @@ import pytest
 
 from fastapi.testclient import TestClient
 
-from aurweb import captcha, db
+from aurweb import captcha, db, logging
 from aurweb.asgi import app
 from aurweb.db import create, query
 from aurweb.models.accepted_term import AcceptedTerm
@@ -32,7 +31,7 @@ TEST_EMAIL = "test@example.org"
 client = TestClient(app)
 user = None
 
-logger = logging.getLogger(__name__)
+logger = logging.get_logger(__name__)
 
 
 def make_ssh_pubkey():

test/test_logging.py

@@ -0,0 +1,16 @@
+from aurweb import logging
+
+logger = logging.get_logger(__name__)
+
+
+def test_logging(caplog):
+    logger.info("Test log.")
+
+    # Test that we logged once.
+    assert len(caplog.records) == 1
+
+    # Test that our log record was of INFO level.
+    assert caplog.records[0].levelname == "INFO"
+
+    # Test that our message got logged.
+    assert "Test log." in caplog.text

test/test_rss.py

@@ -1,5 +1,3 @@
-import logging
-
 from datetime import datetime
 from http import HTTPStatus
 
@@ -8,7 +6,7 @@ import pytest
 
 from fastapi.testclient import TestClient
 
-from aurweb import db
+from aurweb import db, logging
 from aurweb.asgi import app
 from aurweb.models.account_type import AccountType
 from aurweb.models.package import Package
@@ -16,7 +14,7 @@ from aurweb.models.package_base import PackageBase
 from aurweb.models.user import User
 from aurweb.testing import setup_test_db
 
-logger = logging.getLogger(__name__)
+logger = logging.get_logger(__name__)
 
 
 @pytest.fixture(autouse=True)