From 8ba34baf8d64258d9ec0dbd41d8e17d7e86dc8bb Mon Sep 17 00:00:00 2001 From: arl Date: Wed, 20 Apr 2022 23:48:11 -0400 Subject: [PATCH] logging: add config for trace loggers and logging directory (#118) * logging: add config for trace loggers and logging directory - allow configuring loggers and their specified levels Some loggers can get spammy when debugging, this allows turning them down, or setting other loggers to lower levels than the root To use, set a MODMAIL_{level}_LOGGERS environment variable, delimiting the loggers with `,` Valid levels are all of the valid levels for logging, as follows trace, debug, info, notice, warning, error, critical - add support for configuring the file logging directory The directory for logging files was fully dependent on the current working directory This caused my environment to be littered with logging directories The solution to this was to continue to use the current working directory, unless the parent directory of the bot is also a parent of the cwd, in which case the bot parent directory is used for creating the logging directory. In addition, `MODMAIL_LOGGING_DIRECTORY` has been added as an override environment variable. Setting it will use that directory for logging. * dispatcher: import ModmailLogger from the correct module * logging: add changelog entry * deps: add python-dotenv as a top level dependency * fix: skip trace logging if the log level isn't enabled * fix: fully resolve the provided logging dir --- docs/changelog.md | 1 + modmail/__init__.py | 25 ++--- modmail/dispatcher.py | 2 +- modmail/log.py | 107 +++++++++++++++++++- poetry.lock | 8 +- pyproject.toml | 2 +- requirements.txt | 2 +- tests/modmail/{test_logs.py => test_log.py} | 3 + 8 files changed, 127 insertions(+), 23 deletions(-) rename tests/modmail/{test_logs.py => test_log.py} (91%) diff --git a/docs/changelog.md b/docs/changelog.md index 37033831..663988f7 100644 --- a/docs/changelog.md +++ b/docs/changelog.md @@ -24,6 +24,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Changed - Embedified the meta commands so they have a nicer UI (#78) +- Improved the logging system to allow trace logging and a specific logging directory to be configured. (#118) ## [0.2.0] - 2021-09-29 diff --git a/modmail/__init__.py b/modmail/__init__.py index 708274df..faf194f1 100644 --- a/modmail/__init__.py +++ b/modmail/__init__.py @@ -2,11 +2,10 @@ import logging import logging.handlers import os -from pathlib import Path import coloredlogs -from modmail.log import ModmailLogger, get_log_level_from_name +from modmail import log try: @@ -22,24 +21,17 @@ if os.name == "nt": asyncio.set_event_loop_policy(asyncio.WindowsSelectorEventLoopPolicy()) -logging.TRACE = 5 -logging.NOTICE = 25 -logging.addLevelName(logging.TRACE, "TRACE") -logging.addLevelName(logging.NOTICE, "NOTICE") - - LOG_FILE_SIZE = 8 * (2**10) ** 2 # 8MB, discord upload limit -# this logging level is set to logging.TRACE because if it is not set to the lowest level, -# the child level will be limited to the lowest level this is set to. -ROOT_LOG_LEVEL = get_log_level_from_name(os.environ.get("MODMAIL_LOG_LEVEL", logging.TRACE)) + +ROOT_LOG_LEVEL = log.get_logging_level() FMT = "%(asctime)s %(levelname)10s %(name)15s - [%(lineno)5d]: %(message)s" DATEFMT = "%Y/%m/%d %H:%M:%S" -logging.setLoggerClass(ModmailLogger) +logging.setLoggerClass(log.ModmailLogger) -# Set up file logging -log_file = Path("logs", "bot.log") +# Set up file logging relative to the current path +log_file = log.get_log_dir() / "bot.log" log_file.parent.mkdir(parents=True, exist_ok=True) # file handler @@ -64,7 +56,7 @@ coloredlogs.install(level=logging.TRACE, fmt=FMT, datefmt=DATEFMT) # Create root logger -root: ModmailLogger = logging.getLogger() +root: log.ModmailLogger = logging.getLogger() root.setLevel(ROOT_LOG_LEVEL) root.addHandler(file_handler) @@ -73,3 +65,6 @@ logging.getLogger("websockets").setLevel(logging.ERROR) # Set asyncio logging back to the default of INFO even if asyncio's debug mode is enabled. logging.getLogger("asyncio").setLevel(logging.INFO) + +# set up trace loggers +log.set_logger_levels() diff --git a/modmail/dispatcher.py b/modmail/dispatcher.py index 5de7d721..929aedc8 100644 --- a/modmail/dispatcher.py +++ b/modmail/dispatcher.py @@ -4,7 +4,7 @@ import logging from typing import Callable, Coroutine, Dict, List, Optional, Tuple, Union -from modmail import ModmailLogger +from modmail.log import ModmailLogger from modmail.utils.general import module_function_disidenticality diff --git a/modmail/log.py b/modmail/log.py index 85754943..0fe13469 100644 --- a/modmail/log.py +++ b/modmail/log.py @@ -1,5 +1,22 @@ +import functools import logging -from typing import Any, Union +import pathlib +from typing import Any, Dict, Union + + +__all__ = [ + "DEFAULT", + "get_logging_level", + "set_logger_levels", + "ModmailLogger", +] + +logging.TRACE = 5 +logging.NOTICE = 25 +logging.addLevelName(logging.TRACE, "TRACE") +logging.addLevelName(logging.NOTICE, "NOTICE") + +DEFAULT = logging.INFO def get_log_level_from_name(name: Union[str, int]) -> int: @@ -13,6 +30,94 @@ def get_log_level_from_name(name: Union[str, int]) -> int: return value +@functools.lru_cache(maxsize=32) +def _get_env() -> Dict[str, str]: + import os + + try: + from dotenv import dotenv_values + except ModuleNotFoundError: + dotenv_values = lambda *args, **kwargs: dict() # noqa: E731 + + return {**dotenv_values(), **os.environ} + + +def get_logging_level() -> None: + """Get the configured logging level, defaulting to logging.INFO.""" + key = "MODMAIL_LOG_LEVEL" + + level = _get_env().get(key, DEFAULT) + + try: + level = int(level) + except TypeError: + level = DEFAULT + except ValueError: + level = level.upper() + if hasattr(logging, level) and isinstance(level := getattr(logging, level), int): + return level + print( + f"Environment variable {key} must be able to be converted into an integer.\n" + f"To resolve this issue, set {key} to an integer value, or remove it from the environment.\n" + "It is also possible that it is sourced from an .env file." + ) + exit(1) + + return level + + +def set_logger_levels() -> None: + """ + Set all loggers to the provided environment variables. + + eg MODMAIL_LOGGERS_TRACE will be split by `,` and each logger will be set to the trace level + This is applied for every logging level. + """ + env_vars = _get_env() + fmt_key = "MODMAIL_LOGGERS_{level}" + + for level in ["trace", "debug", "info", "notice", "warning", "error", "critical"]: + level = level.upper() + key = fmt_key.format(level=level) + loggers: str = env_vars.get(key, None) + if loggers is None: + continue + + for logger in loggers.split(","): + logging.getLogger(logger.strip()).setLevel(level) + + +def get_log_dir() -> pathlib.Path: + """ + Return a directory to be used for logging. + + The log directory is made in the current directory + unless the current directory shares a parent directory with the bot. + + This is ignored if a environment variable provides the logging directory. + """ + env_vars = _get_env() + key = "MODMAIL_LOGGING_DIRECTORY" + if log_dir := env_vars.get(key, None): + # return the log dir if its absolute, otherwise use the root/cwd trick + path = pathlib.Path(log_dir).expanduser() + if path.is_absolute(): + return path + + log_dir = log_dir or "logs" + + # Get the directory above the bot module directory + path = pathlib.Path(__file__).parents[1] + cwd = pathlib.Path.cwd() + try: + cwd.relative_to(path) + except ValueError: + log_path = path / log_dir + else: + log_path = cwd / log_dir + return log_path.resolve() + + class ModmailLogger(logging.Logger): """Custom logging class implementation.""" diff --git a/poetry.lock b/poetry.lock index 1119dd5d..0feff50a 100644 --- a/poetry.lock +++ b/poetry.lock @@ -977,7 +977,7 @@ six = ">=1.5" [[package]] name = "python-dotenv" -version = "0.19.0" +version = "0.19.2" description = "Read key-value pairs from a .env file and set them as environment variables" category = "main" optional = false @@ -1183,7 +1183,7 @@ yaml = ["PyYAML"] [metadata] lock-version = "1.1" python-versions = "^3.8" -content-hash = "4eaebb69142186eb444698004183844720ad7436976eb465ce0b45310f9f4c27" +content-hash = "6b08e56ec00c0ccae344ff7844344a4bc42143f66638f071992bdafaa81852fe" [metadata.files] aiodns = [ @@ -1903,8 +1903,8 @@ python-dateutil = [ {file = "python_dateutil-2.8.2-py2.py3-none-any.whl", hash = "sha256:961d03dc3453ebbc59dbdea9e4e11c5651520a876d0f4db161e8674aae935da9"}, ] python-dotenv = [ - {file = "python-dotenv-0.19.0.tar.gz", hash = "sha256:f521bc2ac9a8e03c736f62911605c5d83970021e3fa95b37d769e2bbbe9b6172"}, - {file = "python_dotenv-0.19.0-py2.py3-none-any.whl", hash = "sha256:aae25dc1ebe97c420f50b81fb0e5c949659af713f31fdb63c749ca68748f34b1"}, + {file = "python-dotenv-0.19.2.tar.gz", hash = "sha256:a5de49a31e953b45ff2d2fd434bbc2670e8db5273606c1e737cc6b93eff3655f"}, + {file = "python_dotenv-0.19.2-py2.py3-none-any.whl", hash = "sha256:32b2bdc1873fd3a3c346da1c6db83d0053c3c62f28f1f38516070c4c8971b1d3"}, ] pyyaml = [ {file = "PyYAML-5.4.1-cp27-cp27m-macosx_10_9_x86_64.whl", hash = "sha256:3b2b1824fe7112845700f815ff6a489360226a5609b96ec2190a45e62a9fc922"}, diff --git a/pyproject.toml b/pyproject.toml index d7fdc563..681d3940 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -19,11 +19,11 @@ arrow = "^1.1.1" colorama = "^0.4.3" coloredlogs = "^15.0" "discord.py" = { url = "https://github.com/Rapptz/discord.py/archive/45d498c1b76deaf3b394d17ccf56112fa691d160.zip" } +python-dotenv = "^0.19.2" atoml = "^1.0.3" attrs = "^21.2.0" desert = "^2020.11.18" marshmallow = "~=3.13.0" -python-dotenv = "^0.19.0" PyYAML = { version = "^5.4.1", optional = true } typing-extensions = "^3.10.0.2" marshmallow-enum = "^1.5.1" diff --git a/requirements.txt b/requirements.txt index fc3854a3..697589ef 100644 --- a/requirements.txt +++ b/requirements.txt @@ -25,7 +25,7 @@ pycares==4.1.2 pycparser==2.20 ; python_version >= "2.7" and python_version != "3.0" and python_version != "3.1" and python_version != "3.2" and python_version != "3.3" pyreadline3==3.3 ; sys_platform == "win32" python-dateutil==2.8.2 ; python_version != "3.0" -python-dotenv==0.19.0 ; python_version >= "3.5" +python-dotenv==0.19.2 ; python_version >= "3.5" pyyaml==5.4.1 ; python_version >= "2.7" and python_version != "3.0" and python_version != "3.1" and python_version != "3.2" and python_version != "3.3" and python_version != "3.4" and python_version != "3.5" six==1.16.0 ; python_version >= "2.7" and python_version != "3.0" and python_version != "3.1" and python_version != "3.2" typing-extensions==3.10.0.2 diff --git a/tests/modmail/test_logs.py b/tests/modmail/test_log.py similarity index 91% rename from tests/modmail/test_logs.py rename to tests/modmail/test_log.py index 97fffaf1..5a128bf3 100644 --- a/tests/modmail/test_logs.py +++ b/tests/modmail/test_log.py @@ -47,6 +47,9 @@ def test_notice_level(log: ModmailLogger) -> None: @pytest.mark.dependency(depends=["create_logger"]) def test_trace_level(log: ModmailLogger) -> None: """Test trace logging level prints a trace response.""" + if not log.isEnabledFor(logging.TRACE): + pytest.skip("Skipping because logging isn't enabled for the necessary level") + trace_test_phrase = "Getting in the weeds" stdout = io.StringIO()