Merge pull request #28 from AstarVienna/fh/colorlog

Add `ColoredFormatter` for logging

README.md

@@ -21,6 +21,11 @@ The package currently contains the following public functions and classes:
 - `Badge` and subclasses: a family of custom markdown report badges. See docstring for details.
 - `BadgeReport`: context manager for collection and generation of report badges. See docstring for details and usage.
 - `get_logger()`: convenience function to get (or create) a logger with given `name` as a child of the universal `astar` logger.
+- `get_astar_logger()`: convenience function to get (or create) a logger with the name `astar`, which serves as the root for all A*V packages and applications.
+
+### Loggers module
+
+- `loggers.ColoredFormatter`: a subclass of `logging.Formatter` to produce colored logging messages for console output.
 
 ## Dependencies
 

astar_utils/__init__.py

@@ -3,4 +3,4 @@
 from .nested_mapping import NestedMapping
 from .unique_list import UniqueList
 from .badges import Badge, BadgeReport
-from .loggers import get_logger
+from .loggers import get_logger, get_astar_logger

astar_utils/loggers.py

@@ -3,7 +3,71 @@
 
 import logging
 
+from colorama import Fore, Back, Style
 
-def get_logger(name: str):
+
+def get_astar_logger() -> logging.Logger:
+    """Get a logger with name "astar"."""
+    return logging.getLogger("astar")
+
+
+def get_logger(name: str) -> logging.Logger:
     """Get a logger with given name as a child of the "astar" logger."""
-    return logging.getLogger("astar").getChild(name)
+    return get_astar_logger().getChild(name)
+
+
+class ColoredFormatter(logging.Formatter):
+    """Formats colored logging output to console.
+
+    Uses the ``colorama`` package to append console color codes to log message.
+    The colors for each level are defined as a class attribute dict `colors`.
+    Above a certain level, the ``Style.BRIGHT`` modifier is added.
+    This defaults to anything at or above ERROR, but can be modified in the
+    `bright_level` class attribute. Similarly, only above a certain level, the
+    name of the level is added to the output message. This defaults to anyting
+    at or above WARNING, but can be modified in the `show_level` class
+    attribute. The class takes a single optional boolean keyword argument
+    `show_name`, which determines if the logger name will be added to the
+    output message. Any additional `kwargs` are passed along to the base class
+    ``logging.Formatter``.
+
+    Note that unlike the base class, this class currently has no support for
+    different `style` arguments (only '%' supported) or `defaults`.
+    """
+
+    colors = {
+        logging.DEBUG: Fore.CYAN,  # Fore.BLUE,
+        logging.INFO: Fore.GREEN,
+        logging.WARNING: Fore.MAGENTA,  # Fore.CYAN,
+        logging.ERROR: Fore.RED,
+        logging.CRITICAL: Fore.YELLOW + Back.RED
+    }
+    show_level = logging.WARNING
+    bright_level = logging.ERROR
+
+    def __init__(self, show_name: bool = True, **kwargs):
+        self._show_name = show_name
+        super().__init__(**kwargs)
+
+    def __repr__(self) -> str:
+        """Return repr(self)."""
+        return f"<{self.__class__.__name__}>"
+
+    def _get_fmt(self, level: int) -> str:
+        log_fmt = [
+            self.colors.get(level),
+            Style.BRIGHT * (level >= self.bright_level),
+            "%(name)s - " * self._show_name,
+            "%(levelname)s: " * (level >= self.show_level),
+            "%(message)s" + Style.RESET_ALL,
+        ]
+        return "".join(log_fmt)
+
+    def formatMessage(self, record):
+        """Override `logging.Formatter.formatMessage()`."""
+        log_fmt = self._get_fmt(record.levelno)
+        return log_fmt % record.__dict__
+
+    # Could maybe add bug_report here somehow?
+    # def formatException(self, ei):
+    #     return super().formatException(ei) + "\n\nextra text"

pyproject.toml

@@ -21,6 +21,7 @@ classifiers = [
 python = "^3.9"
 more-itertools = "^10.1.0"
 pyyaml = "^6.0.1"
+colorama = "^0.4.6"
 
 
 [tool.poetry.group.test.dependencies]

tests/test_loggers.py

@@ -0,0 +1,113 @@
+# -*- coding: utf-8 -*-
+"""Unit tests for loggers.py."""
+
+import logging
+from importlib import reload
+from io import StringIO
+
+import pytest
+
+from astar_utils.loggers import get_astar_logger, get_logger, ColoredFormatter
+
+
+@pytest.fixture(scope="class", autouse=True)
+def reset_logging():
+    logging.shutdown()
+    reload(logging)
+    yield
+    logging.shutdown()
+
+
+@pytest.fixture(scope="class")
+def base_logger():
+    return get_astar_logger()
+
+
+@pytest.fixture(scope="class")
+def child_logger():
+    return get_logger("test")
+
+
+class TestBaseLogger:
+    def test_name(self, base_logger):
+        assert base_logger.name == "astar"
+
+    def test_parent(self, base_logger):
+        assert base_logger.parent.name == "root"
+
+    def test_initial_level(self, base_logger):
+        assert base_logger.level == 0
+
+    def test_has_no_handlers(self, base_logger):
+        assert not base_logger.handlers
+
+
+class TestChildLogger:
+    def test_name(self, child_logger):
+        assert child_logger.name == "astar.test"
+
+    def test_parent(self, child_logger):
+        assert child_logger.parent.name == "astar"
+
+    def test_initial_level(self, child_logger):
+        assert child_logger.level == 0
+
+    def test_has_no_handlers(self, child_logger):
+        assert not child_logger.handlers
+
+    def test_level_propagates(self, base_logger, child_logger):
+        base_logger.setLevel("ERROR")
+        assert child_logger.getEffectiveLevel() == 40
+
+
+class TestColoredFormatter:
+    def test_repr(self):
+        assert f"{ColoredFormatter()!r}" == "<ColoredFormatter>"
+
+    def test_levels_are_ints(self):
+        colf = ColoredFormatter()
+        assert isinstance(colf.show_level, int)
+        assert isinstance(colf.bright_level, int)
+        for key in colf.colors:
+            assert isinstance(key, int)
+
+    def test_colors_are_valid(self):
+        colf = ColoredFormatter()
+        for value in colf.colors.values():
+            assert value.startswith("\x1b[")
+
+    @pytest.mark.parametrize("level",
+                             ["CRITICAL", "ERROR", "WARNING", "INFO", "DEBUG"])
+    def test_colors_are_in_log_msg(self, level, base_logger,
+                                   child_logger, caplog):
+        with StringIO() as str_stream:
+            # need string stream handler to capture color codes
+            handler1 = logging.StreamHandler(stream=str_stream)
+            handler2 = logging.StreamHandler()  # sys.stdout
+            handler1.setFormatter(ColoredFormatter())
+            handler2.setFormatter(ColoredFormatter())
+            handler1.setLevel(logging.DEBUG)
+            handler2.setLevel(logging.DEBUG)
+            base_logger.addHandler(handler1)
+            base_logger.addHandler(handler2)
+            base_logger.propagate = True
+            base_logger.setLevel(logging.DEBUG)
+
+            int_level = logging.getLevelName(level)
+            print(f"\nTest logging level: {level}:")
+            child_logger.log(int_level, "foo")
+
+            # release the handler to avoid I/O on closed stream errors
+            base_logger.removeHandler(handler1)
+            base_logger.removeHandler(handler2)
+            del handler1
+            del handler2
+
+            assert level in caplog.text
+            assert "foo" in caplog.text
+            assert "astar.test" in caplog.text
+
+            # caplog.text seems to strip the color codes...
+            colored_text = str_stream.getvalue()
+            assert colored_text.startswith("\x1b[")
+            assert colored_text.strip().endswith("\x1b[0m")