From a06f4ec19c559c836fac7e65abd1e44a08175154 Mon Sep 17 00:00:00 2001 From: Kevin Morris Date: Thu, 21 Oct 2021 10:08:45 -0700 Subject: [PATCH] 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 --- aurweb/logging.py | 12 +++++++++++- aurweb/redis.py | 6 +++--- aurweb/routers/accounts.py | 5 ++--- aurweb/routers/trusted_user.py | 5 ++--- aurweb/scripts/rendercomment.py | 5 +++-- aurweb/util.py | 5 +++-- logging.conf | 4 ++-- test/test_accounts_routes.py | 5 ++--- test/test_logging.py | 16 ++++++++++++++++ test/test_rss.py | 6 ++---- 10 files changed, 46 insertions(+), 23 deletions(-) create mode 100644 test/test_logging.py diff --git a/aurweb/logging.py b/aurweb/logging.py index d0154634..5c4a7b6a 100644 --- a/aurweb/logging.py +++ b/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) diff --git a/aurweb/redis.py b/aurweb/redis.py index 6d3cff38..e29b8e37 100644 --- a/aurweb/redis.py +++ b/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 diff --git a/aurweb/routers/accounts.py b/aurweb/routers/accounts.py index 3e134e7a..a4f6dc56 100644 --- a/aurweb/routers/accounts.py +++ b/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) diff --git a/aurweb/routers/trusted_user.py b/aurweb/routers/trusted_user.py index 5b2a56d3..7c0a0404 100644 --- a/aurweb/routers/trusted_user.py +++ b/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. diff --git a/aurweb/scripts/rendercomment.py b/aurweb/scripts/rendercomment.py index 355ca050..a00448d8 100755 --- a/aurweb/scripts/rendercomment.py +++ b/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') diff --git a/aurweb/util.py b/aurweb/util.py index cccbe9d8..f3048efe 100644 --- a/aurweb/util.py +++ b/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): diff --git a/logging.conf b/logging.conf index e0959916..ba41fb7b 100644 --- a/logging.conf +++ b/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 diff --git a/test/test_accounts_routes.py b/test/test_accounts_routes.py index 9252e5bf..d5d92112 100644 --- a/test/test_accounts_routes.py +++ b/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(): diff --git a/test/test_logging.py b/test/test_logging.py new file mode 100644 index 00000000..63092d07 --- /dev/null +++ b/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 diff --git a/test/test_rss.py b/test/test_rss.py index ce3bc71f..40607ade 100644 --- a/test/test_rss.py +++ b/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)