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

@@ -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
 

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()

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
 
 

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."""
 

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"

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

tests/modmail/test_logs.py → 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()